Changeset 1462

Show
Ignore:
Timestamp:
11/22/08 13:32:55 (12 years ago)
Author:
ppalmers
Message:

fix subtle wraparound bug in cycle timer reconstruction code

Files:

Legend:

Unmodified
Added
Removed
Modified
Copied
Moved
  • branches/libffado-2.0/src/libieee1394/IsoHandler.cpp

    r1447 r1462  
    379379                    unsigned char channel, unsigned char tag, unsigned char sy, 
    380380                    unsigned int cycle, unsigned int dropped) { 
    381  
    382381    // keep track of dropped cycles 
    383382    int dropped_cycles = 0; 
     
    399398    m_last_cycle = cycle; 
    400399 
    401     uint32_t pkt_ctr = cycle << 12; 
    402  
    403     // if we assume that one iterate() loop doesn't take longer than 0.5 seconds, 
    404     // the seconds field won't change while the iterate loop runs 
    405     // this means that we can preset 'now' before running iterate() 
    406     uint32_t now_secs = CYCLE_TIMER_GET_SECS(m_last_now); 
    407     // causality results in the fact that 'now' is always after 'cycle' 
    408     // except if additional packets are received between setting the 
    409     // m_last_now and the starting the iterate() loop. 
    410     // this causes the m_last_now to be set at a time before the last packet 
    411     // in this loop is received. however, it's not going to be >4000 cycles. 
    412     // hence: 
    413     // - if the m_last_now > cycle, there is no need to unwrap 
    414     //   both values are within the same second 
    415     // - if m_last_now < cycle it can mean two things: 
    416     //    * m_last_now has wrapped, but is still later than cycle 
    417     //      hence diffCycles(m_last_now, cycle) > 0. We should unwrap 
    418     //    * m_last_now has not wrapped, and cycle is ahead of m_last_now 
    419     //      this means that the cycle is more recent than the saved 
    420     //      m_last_now value 
    421     // . Hence if we calculate 
    422     // the unwrapped difference, and it's larger than 0, this means 
    423     // that m_last_now is after the current cycle. . 
    424     // it m_last_now is before the current cycle, we should not unwrap 
    425     // NOTE: another option is to reread the m_last_now 
    426     if( (CYCLE_TIMER_GET_CYCLES(m_last_now) < cycle) 
    427         && diffCycles(CYCLE_TIMER_GET_CYCLES(m_last_now), cycle) >= 0) { 
    428         debugOutputExtreme(DEBUG_LEVEL_VERBOSE, 
    429                            "unwrapping %d => %d, %d\n", 
    430                            CYCLE_TIMER_GET_CYCLES(m_last_now), 
    431                            cycle); 
    432         // the cycle field has wrapped, substract one second 
    433         if(now_secs == 0) { 
    434             now_secs = 127; 
    435         } else  { 
    436             now_secs -= 1; 
    437         } 
    438     } 
    439  
     400    // the m_last_now value is set when the iterate() function is called. 
     401    uint32_t now_cycles = CYCLE_TIMER_GET_CYCLES(m_last_now); 
     402 
     403    // two cases can occur: 
     404    // (1) this packet has been received before iterate() was called (normal case). 
     405    // (2) this packet has been received after iterate() was called. 
     406    //     happens when the kernel flushes more packets while we are already processing. 
     407    // 
     408    // In case (1) now_cycles is a small number of cycles larger than cycle. In 
     409    // case (2) now_cycles is a small number of cycles smaller than cycle. 
     410    // hence  abs(diffCycles(now_cycles, cycles)) has to be 'small' 
     411 
     412    // we can calculate the time of arrival for this packet as 
     413    // 'now' + diffCycles(cycles, now_cycles) * TICKS_PER_CYCLE 
     414    // in its properly wrapped version 
     415    int64_t diff_cycles = diffCycles(cycle, now_cycles); 
     416    int64_t tmp = CYCLE_TIMER_TO_TICKS(m_last_now); 
     417    tmp += diff_cycles * (int64_t)TICKS_PER_CYCLE; 
     418    uint64_t pkt_ctr_ticks = wrapAtMinMaxTicks(tmp); 
     419    uint32_t pkt_ctr = TICKS_TO_CYCLE_TIMER(pkt_ctr_ticks); 
    440420    #ifdef DEBUG 
    441     if( (CYCLE_TIMER_GET_CYCLES(m_last_now) < cycle) 
    442         && diffCycles(CYCLE_TIMER_GET_CYCLES(m_last_now), cycle) < 0 
     421    if( (now_cycles < cycle) 
     422        && diffCycles(now_cycles, cycle) < 0 
    443423        // ignore this on dropped cycles, since it's normal 
    444424        // that now is ahead on the received packets (as we miss packets) 
     
    448428    } 
    449429    #endif 
    450     pkt_ctr |= (now_secs & 0x7F) << 25; 
    451430 
    452431    #if ISOHANDLER_CHECK_CTR_RECONSTRUCTION 
     
    468447    pkt_ctr_ref |= (now_secs_ref & 0x7F) << 25; 
    469448 
    470     if(pkt_ctr != pkt_ctr_ref) { 
     449    if((pkt_ctr & ~0x0FFFL) != pkt_ctr_ref) { 
    471450        debugWarning("reconstructed CTR counter discrepancy\n"); 
    472         debugWarning(" ingredients: %X, %lX, %lX, %lX, %lX, %ld, %ld\n", 
    473                        cycle, pkt_ctr_ref, pkt_ctr, now, m_last_now, now_secs_ref, now_secs); 
     451        debugWarning(" ingredients: %X, %lX, %lX, %lX, %lX, %ld, %ld, %ld, %lld\n", 
     452                       cycle, pkt_ctr_ref, pkt_ctr, now, m_last_now, now_secs_ref, CYCLE_TIMER_GET_SECS(now), CYCLE_TIMER_GET_SECS(m_last_now), tmp); 
     453        debugWarning(" diffcy = %ld \n", diff_cycles); 
    474454    } 
    475455    #endif 
     
    523503        pkt_ctr = 0xFFFFFFFF; 
    524504    } else { 
    525         pkt_ctr = cycle << 12; 
    526  
    527         // if we assume that one iterate() loop doesn't take longer than 0.5 seconds, 
    528         // the seconds field won't change while the iterate loop runs 
    529         // this means that we can preset 'now' before running iterate() 
    530         uint32_t now_secs = CYCLE_TIMER_GET_SECS(m_last_now); 
    531         // causality results in the fact that 'now' is always after 'cycle' 
    532         if(CYCLE_TIMER_GET_CYCLES(m_last_now) > (unsigned int)cycle) { 
    533             // the cycle field has wrapped, add one second 
    534             now_secs += 1; 
    535             // no need for this: 
    536             //if(now_secs == 128) { 
    537             //    now_secs = 0; 
    538             //} 
    539             // since we mask later on 
    540         } 
    541         pkt_ctr |= (now_secs & 0x7F) << 25; 
     505        // the m_last_now value is set when the iterate() function is called. 
     506        uint32_t now_cycles = CYCLE_TIMER_GET_CYCLES(m_last_now); 
     507 
     508        // two cases can occur: 
     509        // (1) this packet has been received before iterate() was called (normal case). 
     510        // (2) this packet has been received after iterate() was called. 
     511        //     happens when the kernel flushes more packets while we are already processing. 
     512        // 
     513        // In case (1) now_cycles is a small number of cycles larger than cycle. In 
     514        // case (2) now_cycles is a small number of cycles smaller than cycle. 
     515        // hence  abs(diffCycles(now_cycles, cycles)) has to be 'small' 
     516 
     517        // we can calculate the time of arrival for this packet as 
     518        // 'now' + diffCycles(cycles, now_cycles) * TICKS_PER_CYCLE 
     519        // in its properly wrapped version 
     520        int64_t diff_cycles = diffCycles(cycle, now_cycles); 
     521        int64_t tmp = CYCLE_TIMER_TO_TICKS(m_last_now); 
     522        tmp += diff_cycles * (int64_t)TICKS_PER_CYCLE; 
     523        uint64_t pkt_ctr_ticks = wrapAtMinMaxTicks(tmp); 
     524        pkt_ctr = TICKS_TO_CYCLE_TIMER(pkt_ctr_ticks); 
    542525 
    543526        #if ISOHANDLER_CHECK_CTR_RECONSTRUCTION 
     
    550533            now_secs_ref += 1; 
    551534            // no need for this: 
    552             //if(now_secs == 128) { 
    553             //    now_secs = 0; 
    554             //} 
    555             // since we mask later on 
     535            if(now_secs_ref == 128) { 
     536               now_secs_ref = 0; 
     537            } 
    556538        } 
    557539        uint32_t pkt_ctr_ref = cycle << 12; 
    558540        pkt_ctr_ref |= (now_secs_ref & 0x7F) << 25; 
    559541 
    560         if(pkt_ctr != pkt_ctr_ref) { 
     542        if((pkt_ctr & ~0x0FFFL) != pkt_ctr_ref) { 
    561543            debugWarning("reconstructed CTR counter discrepancy\n"); 
    562             pkt_ctr=pkt_ctr_ref; 
     544            debugWarning(" ingredients: %X, %lX, %lX, %lX, %lX, %ld, %ld, %ld, %lld\n", 
     545                        cycle, pkt_ctr_ref, pkt_ctr, now, m_last_now, now_secs_ref, CYCLE_TIMER_GET_SECS(now), CYCLE_TIMER_GET_SECS(m_last_now), tmp); 
     546            debugWarning(" diffcy = %ld \n", diff_cycles); 
    563547        } 
    564548        #endif 
  • branches/libffado-2.0/src/libieee1394/IsoHandlerManager.cpp

    r1432 r1462  
    345345        } 
    346346    } 
     347 
    347348    if(handler_died) { 
    348349        m_running = false;