Changeset 879

Show
Ignore:
Timestamp:
02/20/08 10:27:57 (13 years ago)
Author:
ppalmers
Message:

- improve cycle timer DLL

  • make it robust against bogus CTR reads
  • remove offset introduced by delay between wakeup and CTR read

prediction performance is now around 100 ticks for a 50ms update loop.

Files:

Legend:

Unmodified
Added
Removed
Modified
Copied
Moved
  • trunk/libffado/src/libieee1394/cycletimer.h

    r866 r879  
    3636#define CYCLES_PER_SECOND   8000U 
    3737#define TICKS_PER_CYCLE     3072U 
     38#define TICKS_PER_HALFCYCLE (3072U/2U) 
    3839#define TICKS_PER_SECOND    24576000UL 
    3940#define TICKS_PER_USEC     (24.576000) 
  • trunk/libffado/src/libieee1394/CycleTimerHelper.cpp

    r878 r879  
    127127    debugOutput( DEBUG_LEVEL_VERBOSE, "Initialize %p...\n", this); 
    128128    pthread_mutex_init(&m_compute_vars_lock, NULL); 
     129     
     130    // initialize the 'prev ctr' values 
     131    uint64_t local_time; 
     132    int maxtries2 = 10; 
     133    do { 
     134        if(!m_Parent.readCycleTimerReg(&m_cycle_timer_prev, &local_time)) { 
     135            debugError("Could not read cycle timer register\n"); 
     136            return false; 
     137        } 
     138        if (m_cycle_timer_prev == 0) { 
     139            debugOutput(DEBUG_LEVEL_VERBOSE, 
     140                        "Bogus CTR: %08X on try %02d\n", 
     141                        m_cycle_timer_prev, maxtries2); 
     142        } 
     143    } while (m_cycle_timer_prev == 0 && maxtries2--); 
     144    m_cycle_timer_ticks_prev = CYCLE_TIMER_TO_TICKS(m_cycle_timer_prev); 
    129145    return true; 
    130146} 
     
    174190        ffado_microsecs_t now = m_TimeSource.getCurrentTimeAsUsecs(); 
    175191        int sleep_time = m_sleep_until - now; 
    176         debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "(%p) Sleep until %lld/%f (now: %lld, diff=%d) ...\n", 
     192        debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, "(%p) Sleep until %lld/%f (now: %lld, diff=%d) ...\n", 
    177193                    this, m_sleep_until, m_next_time_usecs, now, sleep_time); 
    178194        m_TimeSource.SleepUsecAbsolute(m_sleep_until); 
    179         debugOutput( DEBUG_LEVEL_VERY_VERBOSE, " (%p) back...\n", this); 
     195        debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, " (%p) back...\n", this); 
    180196    } 
    181197 
    182198    uint32_t cycle_timer; 
    183199    uint64_t local_time; 
    184     if(!m_Parent.readCycleTimerReg(&cycle_timer, &local_time)) { 
    185         debugError("Could not read cycle timer register\n"); 
    186         return false; 
    187     } 
     200    int64_t usecs_late; 
     201    int ntries=2; 
     202    uint64_t cycle_timer_ticks; 
     203    double diff_ticks; 
     204 
     205    // if the difference between the predicted value and the 
     206    // actual value seems to be too large, retry reading the cycle timer 
     207    // some host controllers return bogus values on some reads 
     208    // (looks like a non-atomic update of the register) 
     209    do { 
     210        if(!readCycleTimerWithRetry(&cycle_timer, &local_time, 10)) { 
     211            debugError("Could not read cycle timer register\n"); 
     212            return false; 
     213        } 
     214        usecs_late = local_time - m_sleep_until; 
     215        cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(cycle_timer); 
     216        diff_ticks = diffTicks(cycle_timer_ticks, (int64_t)m_next_time_ticks); 
     217        if(diff_ticks < -((double)TICKS_PER_HALFCYCLE)) { 
     218            debugOutput(DEBUG_LEVEL_VERBOSE, "have to retry, diff = %f\n",diff_ticks); 
     219        } 
     220         
     221    } while(diff_ticks < -((double)TICKS_PER_HALFCYCLE) && --ntries && !m_first_run); 
     222 
    188223    debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, " read : CTR: %11lu, local: %17llu\n", 
    189224                        cycle_timer, local_time); 
     
    204239    } else { 
    205240        m_sleep_until += m_usecs_per_update; 
    206         uint64_t cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(cycle_timer); 
    207         double usecs_late = ((double)local_time) - (m_next_time_usecs); 
     241 
     242        double diff_ticks_corr; 
     243        // correct for late wakeup 
     244        int64_t ticks_late = (usecs_late * TICKS_PER_SECOND) / 1000000LL; 
     245        if (ticks_late > 0) { 
     246            // if we are usecs_late usecs late  
     247            // the cycle timer has ticked approx ticks_late ticks too much 
     248            cycle_timer_ticks = substractTicks(cycle_timer_ticks, ticks_late); 
     249            diff_ticks_corr = diff_ticks - ticks_late; 
     250        } else { 
     251            debugError("Early wakeup, should not happen!\n"); 
     252            // recover 
     253            cycle_timer_ticks = addTicks(cycle_timer_ticks, -ticks_late); 
     254            diff_ticks_corr = diff_ticks + ticks_late; 
     255        } 
     256 
     257        #ifdef DEBUG 
     258        if(usecs_late > 20) { 
     259            debugWarning("Rather late wakeup: %lld usecs\n", usecs_late); 
     260        } 
     261        #endif 
    208262 
    209263        // update the x-axis values 
    210         double diff_ticks = diffTicks(cycle_timer_ticks, (int64_t)m_next_time_ticks); 
    211264        m_current_time_ticks = m_next_time_ticks; 
     265 
    212266        // do the calculation in 'tick space' 
    213         int64_t tmp = (uint64_t)(DLL_COEFF_B * diff_ticks); 
     267        int64_t tmp = (uint64_t)(DLL_COEFF_B * diff_ticks_corr); 
    214268        if(m_dll_e2 > 0) { 
    215269            tmp = addTicks(tmp, (uint64_t)m_dll_e2); 
     
    224278        // it should be ok to not do this in tick space since it's value 
    225279        // is approx equal to the rate, being 24.576 ticks/usec 
    226         m_dll_e2 += DLL_COEFF_C * diff_ticks; 
     280        m_dll_e2 += DLL_COEFF_C * diff_ticks_corr; 
     281 
     282        // For jitter graphs 
     283        //debugOutputShort(DEBUG_LEVEL_NORMAL, "0123456789 %f %f %f %lld %lld %lld\n",  
     284        //                 diff_ticks, diff_ticks_corr, m_dll_e2, cycle_timer_ticks, (int64_t)m_next_time_ticks, usecs_late); 
    227285 
    228286        // update the y-axis values 
    229287        m_current_time_usecs = m_next_time_usecs; 
    230         m_next_time_usecs = local_time + m_usecs_per_update; 
    231  
    232         debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, " usecs: current: %f next: %f usecs_late=%f\n", 
    233                             m_current_time_usecs, m_next_time_usecs, usecs_late); 
     288        m_next_time_usecs += m_usecs_per_update; 
     289 
     290        debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, " usecs: current: %f next: %f usecs_late=%lld ticks_late=%lld\n", 
     291                            m_current_time_usecs, m_next_time_usecs, usecs_late, ticks_late); 
    234292        debugOutputExtreme( DEBUG_LEVEL_VERY_VERBOSE, " ticks: current: %f next: %f diff=%f\n", 
    235293                            m_current_time_ticks, m_next_time_ticks, diff_ticks); 
     
    240298    // FIXME: priority inversion possible, run this at higher prio than client threads 
    241299    ENTER_CRITICAL_SECTION; 
    242     m_current_vars.ticks = (uint64_t)(m_current_time_ticks);// + m_average_offset_ticks); 
     300    m_current_vars.ticks = (uint64_t)(m_current_time_ticks); 
    243301    m_current_vars.usecs = (uint64_t)m_current_time_usecs; 
    244302    m_current_vars.rate = getRate(); 
     
    344402CycleTimerHelper::getCycleTimer() 
    345403{ 
    346     bool good=false; 
    347     int maxtries = 10; 
    348404    uint32_t cycle_timer; 
    349405    uint64_t local_time; 
    350      
     406    readCycleTimerWithRetry(&cycle_timer, &local_time, 10); 
     407    return cycle_timer; 
     408
     409 
     410uint32_t 
     411CycleTimerHelper::getCycleTimer(uint64_t now) 
     412
     413    debugWarning("not implemented!\n"); 
     414    return getCycleTimer(); 
     415
     416 
     417#endif 
     418 
     419bool 
     420CycleTimerHelper::readCycleTimerWithRetry(uint32_t *cycle_timer, uint64_t *local_time, int ntries) 
     421
     422    bool good=false; 
     423    int maxtries = ntries; 
     424 
    351425    do { 
    352426        // the ctr read can return 0 sometimes. if that happens, reread the ctr. 
    353         int maxtries2=10
     427        int maxtries2=ntries
    354428        do { 
    355             if(!m_Parent.readCycleTimerReg(&cycle_timer, &local_time)) { 
     429            if(!m_Parent.readCycleTimerReg(cycle_timer, local_time)) { 
    356430                debugError("Could not read cycle timer register\n"); 
    357                 return 0
     431                return false
    358432            } 
    359             if (cycle_timer == 0) { 
     433            if (*cycle_timer == 0) { 
    360434                debugOutput(DEBUG_LEVEL_VERBOSE, 
    361435                           "Bogus CTR: %08X on try %02d\n", 
    362                            cycle_timer, maxtries2); 
     436                           *cycle_timer, maxtries2); 
    363437            } 
    364         } while (cycle_timer == 0 && maxtries2--); 
     438        } while (*cycle_timer == 0 && maxtries2--); 
    365439         
    366440        // catch bogus ctr reads (can happen) 
    367         uint64_t cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(cycle_timer); 
     441        uint64_t cycle_timer_ticks = CYCLE_TIMER_TO_TICKS(*cycle_timer); 
    368442     
    369443        if (diffTicks(cycle_timer_ticks, m_cycle_timer_ticks_prev) < 0) { 
     
    373447            debugOutput( DEBUG_LEVEL_VERBOSE, 
    374448                        "                            : %08X -> %08X\n", 
    375                         m_cycle_timer_prev, cycle_timer); 
     449                        m_cycle_timer_prev, *cycle_timer); 
    376450            debugOutput( DEBUG_LEVEL_VERBOSE, 
    377451                        " current: %011llu (%03us %04ucy %04uticks)\n", 
     
    388462        } else { 
    389463            good = true; 
    390             m_cycle_timer_prev = cycle_timer; 
     464            m_cycle_timer_prev = *cycle_timer; 
    391465            m_cycle_timer_ticks_prev = cycle_timer_ticks; 
    392466        } 
    393467    } while (!good && maxtries--); 
    394     return cycle_timer; 
    395 
    396  
    397 uint32_t 
    398 CycleTimerHelper::getCycleTimer(uint64_t now) 
    399 
    400     debugWarning("not implemented!\n"); 
    401     return getCycleTimer(); 
    402 
    403  
    404 #endif 
     468    return true; 
     469
    405470 
    406471void 
  • trunk/libffado/src/libieee1394/CycleTimerHelper.h

    r878 r879  
    101101 
    102102private: 
     103    bool readCycleTimerWithRetry(uint32_t *cycle_timer, uint64_t *local_time, int ntries); 
     104 
    103105    Ieee1394Service &m_Parent; 
    104106    Util::SystemTimeSource m_TimeSource; 
     
    120122 
    121123    uint32_t m_cycle_timer_prev; 
    122     uint32_t m_cycle_timer_ticks_prev; 
     124    uint64_t m_cycle_timer_ticks_prev; 
    123125 
    124126    // cached vars used for computation 
  • trunk/libffado/tests/test-ieee1394service.cpp

    r864 r879  
    116116        uint64_t ctr_prev; 
    117117        uint64_t ctr_dll_prev; 
     118         
     119        uint64_t nb_checks; 
     120        int64_t summed_diff; 
     121        double avg_diff; 
    118122}; 
    119123 
     
    125129    uint32_t cycle_timer; 
    126130    uint64_t local_time; 
    127     // read the CTR 'raw' from a handle 
    128     // and read it from the 1394 service, which uses a DLL 
    129     int err = raw1394_read_cycle_timer(m_handle, &cycle_timer, &local_time); 
     131    uint32_t cycle_timer2; 
     132    uint64_t local_time2; 
     133    uint64_t ticks1, ticks2; 
     134    int err; 
     135 
     136    do { 
     137        // read the CTR 'raw' from a handle 
     138        // and read it from the 1394 service, which uses a DLL 
     139        err = raw1394_read_cycle_timer(m_handle, &cycle_timer2, &local_time2); 
     140        err = raw1394_read_cycle_timer(m_handle, &cycle_timer, &local_time); 
     141         
     142        ticks1 = CYCLE_TIMER_TO_TICKS(cycle_timer); 
     143        ticks2 = CYCLE_TIMER_TO_TICKS(cycle_timer2); 
     144    } while (diffTicks(ticks1, ticks2) < 0); 
    130145     
    131146    ctr_prev = ctr; 
     
    156171    if (diff > max_diff) max_diff = diff; 
    157172    if (diff < min_diff) min_diff = diff; 
    158  
     173    summed_diff += diff; 
     174    nb_checks++; 
     175    avg_diff = ((double)summed_diff)/((double)nb_checks); 
     176     
    159177    if (diff < 0) { 
    160178        abs_diff = -diff; 
     
    319337    } 
    320338 
    321     i=0; 
     339    int cnt=0; 
    322340    while(run) { 
    323         i++; 
    324         debugOutput(DEBUG_LEVEL_NORMAL, "%08d: alive, (max: %6d, min: %6d)\n", i, max_diff, min_diff); 
     341        cnt++; 
     342        debugOutput(DEBUG_LEVEL_NORMAL, "%08d: (max: %6d, min: %6d)\n", cnt, max_diff, min_diff); 
    325343        m_service->show(); 
     344         
     345        for (i=0; i < NB_THREADS; i++) { 
     346            debugOutput(DEBUG_LEVEL_NORMAL, "%2d: avg: %6f\n", i,  thread_runners[i]->avg_diff); 
     347        } 
     348         
     349         
    326350        sleep(5); 
    327351    }