static int bcm_kona_wdt_dbg_show(struct seq_file *s, void *data) { int ctl_val, cur_val, ret; unsigned long flags; struct bcm_kona_wdt *wdt = s->private; if (!wdt) return seq_puts(s, "No device pointer\n"); spin_lock_irqsave(&wdt->lock, flags); ctl_val = secure_register_read(wdt, SECWDOG_CTRL_REG); cur_val = secure_register_read(wdt, SECWDOG_COUNT_REG); spin_unlock_irqrestore(&wdt->lock, flags); if (ctl_val < 0 || cur_val < 0) { ret = seq_puts(s, "Error accessing hardware\n"); } else { int ctl, cur, ctl_sec, cur_sec, res; ctl = ctl_val & SECWDOG_COUNT_MASK; res = (ctl_val & SECWDOG_RES_MASK) >> SECWDOG_CLKS_SHIFT; cur = cur_val & SECWDOG_COUNT_MASK; ctl_sec = TICKS_TO_SECS(ctl, wdt); cur_sec = TICKS_TO_SECS(cur, wdt); ret = seq_printf(s, "Resolution: %d / %d\n" "Control: %d s / %d (%#x) ticks\n" "Current: %d s / %d (%#x) ticks\n" "Busy count: %lu\n", res, wdt->resolution, ctl_sec, ctl, ctl, cur_sec, cur, cur, wdt->busy_count); } return ret; }
int main() { setDebugLevel(DEBUG_LEVEL_VERY_VERBOSE); printf("Cycle timer operation tests (incomplete)\n"); /* TEST 1 * check reconstruction of SYT RECEIVE timestamp * * The now_ctr has wrapped, while the cycle and syt have not * */ #ifdef DEBUG uint32_t now_ctr = 0x140001DA; uint64_t now = CYCLE_TIMER_TO_TICKS(0x140001DA); unsigned int cycle = 7968; uint16_t syt = 0x583B; #endif debugOutput(DEBUG_LEVEL_VERBOSE,"NOW_CTR : %08X (%03us %04uc %04ut)\n", now_ctr, (unsigned int)CYCLE_TIMER_GET_SECS(now_ctr), (unsigned int)CYCLE_TIMER_GET_CYCLES(now_ctr), (unsigned int)CYCLE_TIMER_GET_OFFSET(now_ctr)); debugOutput(DEBUG_LEVEL_VERBOSE,"NOW : %011llu (%03us %04uc %04ut)\n", now, (unsigned int)TICKS_TO_SECS(now), (unsigned int)TICKS_TO_CYCLES(now), (unsigned int)TICKS_TO_OFFSET(now)); debugOutput(DEBUG_LEVEL_VERBOSE,"SYT : %08X (%03us %04uc %04ut)\n", syt, (unsigned int)CYCLE_TIMER_GET_SECS(syt), (unsigned int)CYCLE_TIMER_GET_CYCLES(syt), (unsigned int)CYCLE_TIMER_GET_OFFSET(syt)); debugOutput(DEBUG_LEVEL_VERBOSE,"CYCLE : %uc\n", cycle); #ifdef DEBUG uint64_t calc_ts = sytRecvToFullTicks(syt, cycle, now_ctr); #endif debugOutput(DEBUG_LEVEL_VERBOSE,"CALC_TS : %011llu (%03us %04uc %04ut)\n", calc_ts, (unsigned int)TICKS_TO_SECS(calc_ts), (unsigned int)TICKS_TO_CYCLES(calc_ts), (unsigned int)TICKS_TO_OFFSET(calc_ts)); // BL: 1211722982: Debug (IsoHandler.cpp)[ 420] putPacket: received packet: length=168, channel=0, cycle=7968 // BL: 1211723031: Debug (cycletimer.h)[ 308] sytRecvToFullTicks: SYT=583B CY=7968 CTR=140001DA // BL: 1211723037: Debug (StreamProcessor.cpp)[ 346] putPacket: RECV: CY=7968 TS=00245679163 // BL: 1211723043: Debug (AmdtpReceiveStreamProcessor.cpp)[ 135] processPacketData: STMP: 245679163ticks | syt_interval=8, tpf=557.254395 // BL: 1211723051: Debug (TimestampedBuffer.cpp)[1153] incrementFrameCounter: nbframes: 8, m_update_period: 8 // BL: 1211723052: Debug (AmdtpTransmitStreamProcessor.cpp)[ 250] generatePacketHeader: Too early: CY=0254, TC=0257, CUT=0003, TST=00271126073 (0257), TSP=00271137849 (0261) // BL: 1211723055: Debug (TimestampedBuffer.cpp)[1155] incrementFrameCounter: tail TS: 270250705.174, next tail TS: 270255163.209 // BL: 1211723062: Debug (TimestampedBuffer.cpp)[1157] incrementFrameCounter: new TS: 245679163.000, wrapped new TS: 245679163.000 // }
bool CycleTimerHelper::readCycleTimerWithRetry(uint32_t *cycle_timer, uint64_t *local_time, int ntries) { bool good=false; int maxtries = ntries; do { // the ctr read can return 0 sometimes. if that happens, reread the ctr. int maxtries2=ntries; do { if(!m_Parent.readCycleTimerReg(cycle_timer, local_time)) { debugError("Could not read cycle timer register\n"); return false; } if (*cycle_timer == 0) { debugOutput(DEBUG_LEVEL_VERBOSE, "Bogus CTR: %08X on try %02d\n", *cycle_timer, maxtries2); } } while (*cycle_timer == 0 && maxtries2--); // catch bogus ctr reads (can happen) uint64_t cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(*cycle_timer); if (diffTicks(cycle_timer_ticks, m_cycle_timer_ticks_prev) < 0) { debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "non-monotonic CTR (try %02d): %"PRIu64" -> %"PRIu64"\n", maxtries, m_cycle_timer_ticks_prev, cycle_timer_ticks); debugOutput( DEBUG_LEVEL_VERY_VERBOSE, " : %08X -> %08X\n", m_cycle_timer_prev, *cycle_timer); debugOutput( DEBUG_LEVEL_VERY_VERBOSE, " current: %011"PRIu64" (%03us %04ucy %04uticks)\n", cycle_timer_ticks, (unsigned int)TICKS_TO_SECS( cycle_timer_ticks ), (unsigned int)TICKS_TO_CYCLES( cycle_timer_ticks ), (unsigned int)TICKS_TO_OFFSET( cycle_timer_ticks ) ); debugOutput( DEBUG_LEVEL_VERY_VERBOSE, " prev : %011"PRIu64" (%03us %04ucy %04uticks)\n", m_cycle_timer_ticks_prev, (unsigned int)TICKS_TO_SECS( m_cycle_timer_ticks_prev ), (unsigned int)TICKS_TO_CYCLES( m_cycle_timer_ticks_prev ), (unsigned int)TICKS_TO_OFFSET( m_cycle_timer_ticks_prev ) ); } else { good = true; m_cycle_timer_prev = *cycle_timer; m_cycle_timer_ticks_prev = cycle_timer_ticks; } } while (!good && maxtries--); return true; }
/* * call with lock held */ bool CycleTimerHelper::initDLL() { uint32_t cycle_timer; uint64_t local_time; double bw_rel = m_dll_coeff_b / (DLL_SQRT2 * DLL_2PI); double bw_abs = bw_rel / (m_usecs_per_update / 1e6); if (bw_rel > 0.5) { double bw_max = 0.5 / (m_usecs_per_update / 1e6); debugWarning("Specified DLL bandwidth too high (%f > %f), reducing to max." " Increase the DLL update rate to increase the max DLL bandwidth\n", bw_abs, bw_max); bw_rel = 0.49; bw_abs = bw_rel / (m_usecs_per_update / 1e6); m_dll_coeff_b = bw_rel * (DLL_SQRT2 * DLL_2PI); m_dll_coeff_c = bw_rel * bw_rel * DLL_2PI * DLL_2PI; } if(!readCycleTimerWithRetry(&cycle_timer, &local_time, 10)) { debugError("Could not read cycle timer register\n"); return false; } #if DEBUG_EXTREME_ENABLE uint64_t cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(cycle_timer); #endif debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, " read : CTR: %11u, local: %17" PRIu64 "\n", cycle_timer, local_time); debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " ctr : 0x%08X %11" PRIu64 " (%03us %04ucy %04uticks)\n", (uint32_t)cycle_timer, (uint64_t)cycle_timer_ticks, (unsigned int)TICKS_TO_SECS( (uint64_t)cycle_timer_ticks ), (unsigned int)TICKS_TO_CYCLES( (uint64_t)cycle_timer_ticks ), (unsigned int)TICKS_TO_OFFSET( (uint64_t)cycle_timer_ticks ) ); m_sleep_until = local_time + m_usecs_per_update; m_dll_e2 = m_ticks_per_update; m_current_time_usecs = local_time; m_next_time_usecs = m_current_time_usecs + m_usecs_per_update; m_current_time_ticks = CYCLE_TIMER_TO_TICKS( cycle_timer ); m_next_time_ticks = addTicks( (uint64_t)m_current_time_ticks, (uint64_t)m_dll_e2); debugOutput(DEBUG_LEVEL_VERBOSE, " (%p) First run\n", this); debugOutput(DEBUG_LEVEL_VERBOSE, " DLL bandwidth: %f Hz (rel: %f)\n", bw_abs, bw_rel); debugOutput(DEBUG_LEVEL_VERBOSE, " usecs/update: %u, ticks/update: %u, m_dll_e2: %f\n", m_usecs_per_update, m_ticks_per_update, m_dll_e2); debugOutput(DEBUG_LEVEL_VERBOSE, " usecs current: %f, next: %f\n", m_current_time_usecs, m_next_time_usecs); debugOutput(DEBUG_LEVEL_VERBOSE, " ticks current: %f, next: %f\n", m_current_time_ticks, m_next_time_ticks); return true; }
static unsigned int bcm_kona_wdt_get_timeleft(struct watchdog_device *wdog) { struct bcm_kona_wdt *wdt = watchdog_get_drvdata(wdog); int val; unsigned long flags; spin_lock_irqsave(&wdt->lock, flags); val = secure_register_read(wdt, SECWDOG_COUNT_REG); spin_unlock_irqrestore(&wdt->lock, flags); if (val < 0) return val; return TICKS_TO_SECS(val & SECWDOG_COUNT_MASK, wdt); }
__u64 process_packet(struct connection *c, __u16 tsp, __u32 *data, size_t len) { struct iec61883_packet *packet = (struct iec61883_packet *) data; assert(packet); int cycle = (tsp >> 0) & 0x1FFF; int sec = (tsp >> 13) & 0x7; bool ok = (packet->fdf != 0xFF) && (packet->fmt == 0x10) && (len >= 2*sizeof(__u32)); __u64 last_timestamp = (__u64)(-1); if(ok) { if(packet->syt != 0xFFFF) { last_timestamp = sytRecvToFullTicks2( (__u32)CondSwapFromBus16(packet->syt), (tsp << 12)); debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "[%02d] %03ds %04dc | %08X %08X | %12lld %03ds %04dc %04dt\n", c->channel, sec, cycle, CondSwapFromBus32(*data), CondSwapFromBus32(*(data+1)), last_timestamp, TICKS_TO_SECS(last_timestamp), TICKS_TO_CYCLES(last_timestamp), TICKS_TO_OFFSET(last_timestamp)); ffado_ringbuffer_write(c->timestamps, (const char *)&last_timestamp, sizeof(last_timestamp)); } else { debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "[%02d] %03ds %04dc | %08X %08X | [empty]\n", c->channel, sec, cycle, CondSwapFromBus32(*data), CondSwapFromBus32(*(data+1))); } } else { debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "[%02d] %03ds %04dc | %08X %08X | [bogus data]\n", c->channel, sec, cycle, CondSwapFromBus32(*data), CondSwapFromBus32(*(data+1))); } return last_timestamp; }
bool CycleTimerHelper::Execute() { debugOutput( DEBUG_LEVEL_ULTRA_VERBOSE, "Execute %p...\n", this); #ifdef DEBUG uint64_t now = m_Parent.getCurrentTimeAsUsecs(); int diff = now - m_last_loop_entry; if(diff < 100) { debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, "(%p) short loop detected (%d usec), cnt: %d\n", this, diff, m_successive_short_loops); m_successive_short_loops++; if(m_successive_short_loops > 100) { debugError("Shutting down runaway thread\n"); return false; } } else { // reset the counter m_successive_short_loops = 0; } m_last_loop_entry = now; #endif if (!m_first_run) { // wait for the next update period //#if DEBUG_EXTREME_ENABLE #ifdef DEBUG ffado_microsecs_t now = Util::SystemTimeSource::getCurrentTimeAsUsecs(); int sleep_time = m_sleep_until - now; debugOutput( DEBUG_LEVEL_ULTRA_VERBOSE, "(%p) Sleep until %"PRId64"/%f (now: %"PRId64", diff=%d) ...\n", this, m_sleep_until, m_next_time_usecs, now, sleep_time); #endif Util::SystemTimeSource::SleepUsecAbsolute(m_sleep_until); debugOutput( DEBUG_LEVEL_ULTRA_VERBOSE, " (%p) back...\n", this); } else { // Since getCycleTimerTicks() is called below, // m_shadow_vars[m_current_shadow_idx] must contain valid data. On // the first run through, however, it won't because the contents of // m_shadow_vars[] are only set later on in this function. Thus // set up some vaguely realistic values to prevent unnecessary // delays when reading the cycle timer for the first time. struct compute_vars new_vars; new_vars.ticks = (uint64_t)(m_current_time_ticks); new_vars.usecs = (uint64_t)m_current_time_usecs; new_vars.rate = getRate(); m_shadow_vars[0] = new_vars; } uint32_t cycle_timer; uint64_t local_time; int64_t usecs_late; int ntries=10; uint64_t cycle_timer_ticks; int64_t err_ticks; bool not_good; // if the difference between the predicted value at readout time and the // actual value seems to be too large, retry reading the cycle timer // some host controllers return bogus values on some reads // (looks like a non-atomic update of the register) do { debugOutput( DEBUG_LEVEL_ULTRA_VERBOSE, "(%p) reading cycle timer register...\n", this); if(!readCycleTimerWithRetry(&cycle_timer, &local_time, 10)) { debugError("Could not read cycle timer register\n"); return false; } usecs_late = local_time - m_sleep_until; cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(cycle_timer); // calculate the CTR_TICKS we expect to read at "local_time" // then calculate the difference with what we actually read, // taking wraparound into account. If these deviate too much // from eachother then read the register again (bogus read). int64_t expected_ticks = getCycleTimerTicks(local_time); err_ticks = diffTicks(cycle_timer_ticks, expected_ticks); // check for unrealistic CTR reads (NEC controller does that sometimes) not_good = (-err_ticks > 1*TICKS_PER_CYCLE || err_ticks > 1*TICKS_PER_CYCLE); if(not_good) { debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) have to retry CTR read, diff unrealistic: diff: %"PRId64", max: +/- %u (try: %d) %"PRId64"\n", this, err_ticks, 1*TICKS_PER_CYCLE, ntries, expected_ticks); // sleep half a cycle to make sure the hardware moved on Util::SystemTimeSource::SleepUsecRelative(USECS_PER_CYCLE / 2); } } while(not_good && --ntries && !m_first_run && !m_unhandled_busreset); // grab the lock after sleeping, otherwise we can't be interrupted by // the busreset thread (lower prio) // also grab it after reading the CTR register such that the jitter between // wakeup and read is as small as possible Util::MutexLockHelper lock(*m_update_lock); // the difference between the measured and the expected time int64_t diff_ticks = diffTicks(cycle_timer_ticks, (int64_t)m_next_time_ticks); // // simulate a random scheduling delay between (0-10ms) // ffado_microsecs_t tmp = Util::SystemTimeSource::SleepUsecRandom(10000); // debugOutput( DEBUG_LEVEL_VERBOSE, " (%p) random sleep of %u usecs...\n", this, tmp); if(m_unhandled_busreset) { debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) Skipping DLL update due to unhandled busreset\n", this); m_sleep_until += m_usecs_per_update; // keep the thread running return true; } debugOutputExtreme( DEBUG_LEVEL_ULTRA_VERBOSE, " read : CTR: %11u, local: %17"PRIu64"\n", cycle_timer, local_time); debugOutputExtreme(DEBUG_LEVEL_ULTRA_VERBOSE, " ctr : 0x%08X %11"PRIu64" (%03us %04ucy %04uticks)\n", (uint32_t)cycle_timer, (uint64_t)cycle_timer_ticks, (unsigned int)TICKS_TO_SECS( (uint64_t)cycle_timer_ticks ), (unsigned int)TICKS_TO_CYCLES( (uint64_t)cycle_timer_ticks ), (unsigned int)TICKS_TO_OFFSET( (uint64_t)cycle_timer_ticks ) ); if (m_first_run) { if(!initDLL()) { debugError("(%p) Could not init DLL\n", this); return false; } m_first_run = false; } else if (diff_ticks > m_ticks_per_update * 20) { debugOutput(DEBUG_LEVEL_VERBOSE, "re-init dll due to too large tick diff: %"PRId64" >> %f\n", diff_ticks, (float)(m_ticks_per_update * 20)); if(!initDLL()) { debugError("(%p) Could not init DLL\n", this); return false; } } else { // calculate next sleep time m_sleep_until += m_usecs_per_update; // correct for the latency between the wakeup and the actual CTR // read. The only time we can trust is the time returned by the // CTR read kernel call, since that (should be) atomically read // together with the ctr register itself. // if we are usecs_late usecs late // the cycle timer has ticked approx ticks_late ticks too much // if we are woken up early (which shouldn't happen according to POSIX) // the cycle timer has ticked approx -ticks_late too little int64_t ticks_late = (usecs_late * TICKS_PER_SECOND) / 1000000LL; // the corrected difference between predicted and actual ctr // i.e. DLL error signal int64_t diff_ticks_corr; if (ticks_late >= 0) { diff_ticks_corr = diff_ticks - ticks_late; debugOutputExtreme(DEBUG_LEVEL_ULTRA_VERBOSE, "diff_ticks_corr=%"PRId64", diff_ticks = %"PRId64", ticks_late = %"PRId64"\n", diff_ticks_corr, diff_ticks, ticks_late); } else { debugError("Early wakeup, should not happen!\n"); // recover diff_ticks_corr = diff_ticks + ticks_late; } #ifdef DEBUG // makes no sense if not running realtime if(m_realtime && usecs_late > 1000) { debugOutput(DEBUG_LEVEL_VERBOSE, "Rather late wakeup: %"PRId64" usecs\n", usecs_late); } #endif // update the x-axis values m_current_time_ticks = m_next_time_ticks; // decide what coefficients to use // it should be ok to not do this in tick space // since diff_ticks_corr should not be near wrapping // (otherwise we are out of range. we need a few calls // w/o wrapping for this to work. That should not be // an issue as long as the update interval is smaller // than the wrapping interval.) // and coeff_b < 1, hence tmp is not near wrapping double diff_ticks_corr_d = (double)diff_ticks_corr; double step_ticks = (m_dll_coeff_b * diff_ticks_corr_d); debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, "diff_ticks_corr=%f, step_ticks=%f\n", diff_ticks_corr_d, step_ticks); // the same goes for m_dll_e2, which should be approx equal // to the ticks/usec rate (= 24.576) hence also not near // wrapping step_ticks += m_dll_e2; debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, "add %f ticks to step_ticks => step_ticks=%f\n", m_dll_e2, step_ticks); // it can't be that we have to update to a value in the past if(step_ticks < 0) { debugError("negative step: %f! (correcting to nominal)\n", step_ticks); // recover to an estimated value step_ticks = (double)m_ticks_per_update; } if(step_ticks > TICKS_PER_SECOND) { debugWarning("rather large step: %f ticks (> 1sec)\n", step_ticks); } // now add the step ticks with wrapping. m_next_time_ticks = (double)(addTicks((uint64_t)m_current_time_ticks, (uint64_t)step_ticks)); // update the DLL state m_dll_e2 += m_dll_coeff_c * diff_ticks_corr_d; // update the y-axis values m_current_time_usecs = m_next_time_usecs; m_next_time_usecs += m_usecs_per_update; debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " usecs: current: %f next: %f usecs_late=%"PRId64" ticks_late=%"PRId64"\n", m_current_time_usecs, m_next_time_usecs, usecs_late, ticks_late); debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " ticks: current: %f next: %f diff=%"PRId64"\n", m_current_time_ticks, m_next_time_ticks, diff_ticks); debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " ticks: current: %011"PRIu64" (%03us %04ucy %04uticks)\n", (uint64_t)m_current_time_ticks, (unsigned int)TICKS_TO_SECS( (uint64_t)m_current_time_ticks ), (unsigned int)TICKS_TO_CYCLES( (uint64_t)m_current_time_ticks ), (unsigned int)TICKS_TO_OFFSET( (uint64_t)m_current_time_ticks ) ); debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " ticks: next : %011"PRIu64" (%03us %04ucy %04uticks)\n", (uint64_t)m_next_time_ticks, (unsigned int)TICKS_TO_SECS( (uint64_t)m_next_time_ticks ), (unsigned int)TICKS_TO_CYCLES( (uint64_t)m_next_time_ticks ), (unsigned int)TICKS_TO_OFFSET( (uint64_t)m_next_time_ticks ) ); debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " state: local: %11"PRIu64", dll_e2: %f, rate: %f\n", local_time, m_dll_e2, getRate()); } // prepare the new compute vars struct compute_vars new_vars; new_vars.ticks = (uint64_t)(m_current_time_ticks); new_vars.usecs = (uint64_t)m_current_time_usecs; new_vars.rate = getRate(); // get the next index unsigned int next_idx = (m_current_shadow_idx + 1) % CTRHELPER_NB_SHADOW_VARS; // update the next index position m_shadow_vars[next_idx] = new_vars; // then we can update the current index m_current_shadow_idx = next_idx; #ifdef DEBUG // do some verification // we re-read a valid ctr timestamp // then we use the attached system time to calculate // the DLL generated timestamp and we check what the // difference is if(!readCycleTimerWithRetry(&cycle_timer, &local_time, 10)) { debugError("Could not read cycle timer register (verify)\n"); return true; // true since this is a check only } cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(cycle_timer); // only check when successful int64_t time_diff = local_time - new_vars.usecs; double y_step_in_ticks = ((double)time_diff) * new_vars.rate; int64_t y_step_in_ticks_int = (int64_t)y_step_in_ticks; uint64_t offset_in_ticks_int = new_vars.ticks; uint32_t dll_time; if (y_step_in_ticks_int > 0) { dll_time = addTicks(offset_in_ticks_int, y_step_in_ticks_int); } else { dll_time = substractTicks(offset_in_ticks_int, -y_step_in_ticks_int); } int32_t ctr_diff = cycle_timer_ticks-dll_time; debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "(%p) CTR DIFF: HW %010"PRIu64" - DLL %010u = %010d (%s)\n", this, cycle_timer_ticks, dll_time, ctr_diff, (ctr_diff>0?"lag":"lead")); #endif return true; }
static unsigned int hpwdt_gettimeleft(struct watchdog_device *wdd) { return TICKS_TO_SECS(ioread16(hpwdt_timer_reg)); }