Index: /branches/libffado-2.0/src/libstreaming/amdtp/AmdtpReceiveStreamProcessor.cpp =================================================================== --- /branches/libffado-2.0/src/libstreaming/amdtp/AmdtpReceiveStreamProcessor.cpp (revision 1528) +++ /branches/libffado-2.0/src/libstreaming/amdtp/AmdtpReceiveStreamProcessor.cpp (revision 1530) @@ -103,5 +103,4 @@ if(ok) { m_last_timestamp = sytRecvToFullTicks2((uint32_t)CondSwapFromBus16(packet->syt), pkt_ctr); - //#ifdef DEBUG #if 0 Index: /branches/libffado-2.0/src/libstreaming/StreamProcessorManager.cpp =================================================================== --- /branches/libffado-2.0/src/libstreaming/StreamProcessorManager.cpp (revision 1528) +++ /branches/libffado-2.0/src/libstreaming/StreamProcessorManager.cpp (revision 1530) @@ -491,4 +491,7 @@ int max_of_min_delay = 0; int min_delay = 0; + int packet_size_frames = 0; + int max_packet_size_frames = 0; + for ( StreamProcessorVectorIterator it = m_ReceiveProcessors.begin(); it != m_ReceiveProcessors.end(); @@ -496,13 +499,23 @@ min_delay = (*it)->getMaxFrameLatency(); if(min_delay > max_of_min_delay) max_of_min_delay = min_delay; - } + packet_size_frames = (*it)->getNominalFramesPerPacket(); + if(packet_size_frames > max_packet_size_frames) max_packet_size_frames = packet_size_frames; + } + for ( StreamProcessorVectorIterator it = m_TransmitProcessors.begin(); + it != m_TransmitProcessors.end(); + ++it ) { + packet_size_frames = (*it)->getNominalFramesPerPacket(); + if(packet_size_frames > max_packet_size_frames) max_packet_size_frames = packet_size_frames; + } + debugOutput( DEBUG_LEVEL_VERBOSE, " max_of_min_delay = %d, max_packet_size_frames = %d...\n", max_of_min_delay, max_packet_size_frames); // add some processing margin. This only shifts the time // at which the buffer is transfer()'ed. This makes things somewhat - // more robust. It should be noted though that shifting the transfer - // time to a later time instant also causes the xmit buffer fill to be - // lower on average. + // more robust. max_of_min_delay += signal_delay_ticks; + // Note that the equivalent number of frames is added to the + // transmit buffer to ensure that it keeps a good buffer fill, no matter + // what the sync delay is. m_SyncSource->setSyncDelay(max_of_min_delay); unsigned int syncdelay = m_SyncSource->getSyncDelay(); @@ -530,5 +543,5 @@ // check if we were woken up too soon time_till_next_period = m_SyncSource->getTimeUntilNextPeriodSignalUsecs(); - debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "waiting for %d usecs...\n", time_till_next_period); + debugOutput( DEBUG_LEVEL_VERBOSE, "waiting for %d usecs...\n", time_till_next_period); if(time_till_next_period > 0) { // wait for the period @@ -549,4 +562,12 @@ } debugOutput( DEBUG_LEVEL_VERBOSE, " sync source frame rate: %f fps (%f tpf)\n", syncrate, tpf); + + m_SyncSource->setSyncDelay(max_of_min_delay); + syncdelay = m_SyncSource->getSyncDelay(); + debugOutput( DEBUG_LEVEL_VERBOSE, " updated sync delay = %d => %d ticks (%f frames) (%03us %04uc %04ut)...\n", + max_of_min_delay, syncdelay, syncdelay/tpf, + (unsigned int)TICKS_TO_SECS(syncdelay), + (unsigned int)TICKS_TO_CYCLES(syncdelay), + (unsigned int)TICKS_TO_OFFSET(syncdelay)); // we now should have decent sync info on the sync source @@ -563,6 +584,14 @@ // this is the time window we have to setup all SP's such that they // can start wet-running correctly. + // we have to round this time to an integer number of audio packets + double time_for_startup_abs = (double)(cycles_for_startup * TICKS_PER_CYCLE); + int time_for_startup_frames = (int)(time_for_startup_abs / tpf); + time_for_startup_frames = ((time_for_startup_frames / max_packet_size_frames) + 1) * max_packet_size_frames; + uint64_t time_for_startup_ticks = (uint64_t)((float)time_for_startup_frames * tpf); + time_of_first_sample = addTicks(time_of_first_sample, - cycles_for_startup * TICKS_PER_CYCLE); + time_for_startup_ticks); + debugOutput( DEBUG_LEVEL_VERBOSE, " add %d frames (%011llu ticks)...\n", + time_for_startup_frames, time_for_startup_ticks); debugOutput( DEBUG_LEVEL_VERBOSE, " => first sample at TS=%011llu (%03us %04uc %04ut)...\n", @@ -571,11 +600,4 @@ (unsigned int)TICKS_TO_CYCLES(time_of_first_sample), (unsigned int)TICKS_TO_OFFSET(time_of_first_sample)); - - #ifdef DEBUG - // the time at which the previous period would have passed is the - // time of the first sample received, minus one frame. - //m_time_of_transfer2 = substractTicks(time_of_first_sample, (uint64_t)m_SyncSource->getTicksPerFrame()); - m_time_of_transfer2 = time_of_first_sample; - #endif // we should start wet-running the transmit SP's some cycles in advance @@ -603,4 +625,9 @@ ++it ) { (*it)->setBufferHeadTimestamp(time_of_first_sample); + ffado_timestamp_t ts; + signed int fc; + (*it)->getBufferHeadTimestamp ( &ts, &fc ); + debugOutput( DEBUG_LEVEL_VERBOSE, " transmit buffer tail %010lld => head TS %010lld, fc=%d...\n", + time_of_first_sample, (uint64_t)ts, fc); } @@ -659,11 +686,19 @@ m_time_of_transfer = m_SyncSource->getTimeAtPeriod(); - // and a (still very rough) approximation of the rate + // and a (rough) approximation of the rate float rate = m_SyncSource->getTicksPerFrame(); + + #ifdef DEBUG + // the time at which the previous period would have passed + m_time_of_transfer2 = m_time_of_transfer; + m_time_of_transfer2 = substractTicks(m_time_of_transfer2, (uint64_t)(m_period * rate)); + #endif + + debugOutput( DEBUG_LEVEL_VERBOSE, " initial time of transfer %010lld, rate %f...\n", + m_time_of_transfer, rate); + int64_t delay_in_ticks = (int64_t)(((float)((m_nb_buffers-1) * m_period)) * rate); // also add the sync delay delay_in_ticks = addTicks(delay_in_ticks, m_SyncSource->getSyncDelay()); - debugOutput( DEBUG_LEVEL_VERBOSE, " initial time of transfer %010lld, rate %f...\n", - m_time_of_transfer, rate); @@ -679,5 +714,4 @@ int64_t transmit_tail_timestamp = addTicks(m_time_of_transfer, delay_in_ticks); - debugOutput( DEBUG_LEVEL_VERBOSE, " preset transmit tail TS %010lld, rate %f...\n", transmit_tail_timestamp, rate); @@ -686,6 +720,11 @@ it != m_TransmitProcessors.end(); ++it ) { + (*it)->setTicksPerFrame(rate); (*it)->setBufferTailTimestamp(transmit_tail_timestamp); - (*it)->setTicksPerFrame(rate); + ffado_timestamp_t ts; + signed int fc; + (*it)->getBufferHeadTimestamp ( &ts, &fc ); + debugOutput( DEBUG_LEVEL_VERBOSE, " => transmit head TS %010lld, fc=%d...\n", + (uint64_t)ts, fc); } Index: /branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.h =================================================================== --- /branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.h (revision 1526) +++ /branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.h (revision 1530) @@ -372,11 +372,14 @@ * @return the sync delay (in ticks) */ - unsigned int getSyncDelay() {return m_sync_delay;}; + unsigned int getSyncDelay(); unsigned int getSyncDelayFrames(); /** * sets the sync delay + * + * note: will be rounded to an integer number of packets + * * @param d sync delay */ - void setSyncDelay(unsigned int d); + void setSyncDelay(unsigned int ticks); /** @@ -449,5 +452,5 @@ float m_ticks_per_frame; float m_dll_bandwidth_hz; - unsigned int m_sync_delay; + unsigned int m_sync_delay_frames; private: bool m_in_xrun; Index: /branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.cpp =================================================================== --- /branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.cpp (revision 1529) +++ /branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.cpp (revision 1530) @@ -77,5 +77,5 @@ , m_ticks_per_frame( 0 ) , m_dll_bandwidth_hz ( STREAMPROCESSOR_DLL_BW_HZ ) - , m_sync_delay( 0 ) + , m_sync_delay_frames( 0 ) , m_in_xrun( false ) { @@ -209,16 +209,27 @@ void -StreamProcessor::setSyncDelay(unsigned int d) { +StreamProcessor::setSyncDelay(unsigned int ticks) { + + // round the sync delay to an integer number of packets now we know the frame rate + int frames = (int)((float)ticks / getTicksPerFrame()); + frames = (frames / getNominalFramesPerPacket()) + 1; + frames *= getNominalFramesPerPacket(); + #ifdef DEBUG - unsigned int frames = (unsigned int)((float)d / getTicksPerFrame()); - debugOutput(DEBUG_LEVEL_VERBOSE, "Setting SP %p SyncDelay to %u ticks, %u frames\n", this, d, frames); + float ticks2 = frames * getTicksPerFrame(); + debugOutput(DEBUG_LEVEL_VERBOSE, "Setting SP %p SyncDelay to %u ticks => rounded to %u frames, %f ticks\n", + this, ticks, frames, ticks2); #endif - m_sync_delay = d; + m_sync_delay_frames = frames; } unsigned int StreamProcessor::getSyncDelayFrames() { - unsigned int frames = (unsigned int)((float)m_sync_delay / getTicksPerFrame()); - return frames; + return m_sync_delay_frames; +} + +unsigned int +StreamProcessor::getSyncDelay() { + return (unsigned int)(m_sync_delay_frames * getTicksPerFrame()); } @@ -414,50 +425,48 @@ fs_nom, fs_syt, fs_diff, fs_diff_norm); } - } - #endif - -// #ifdef DEBUG - int ticks_per_packet = (int)(getTicksPerFrame() * getNominalFramesPerPacket()); - int diff = diffTicks(m_last_timestamp, m_last_timestamp2); - // display message if the difference between two successive tick - // values is more than 50 ticks. 1 sample at 48k is 512 ticks - // so 50 ticks = 10%, which is a rather large jitter value. - if(diff-ticks_per_packet > 50 || diff-ticks_per_packet < -50) { - debugOutput(DEBUG_LEVEL_VERBOSE, - "cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n", - CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2, - m_last_timestamp, diff, ticks_per_packet); - // !!!HACK!!! FIXME: this is the result of a failure in wrapping/unwrapping somewhere - // it's definitely a bug. - // try to fix up the timestamp - int64_t last_timestamp_fixed; - // first try to add one second - last_timestamp_fixed = addTicks(m_last_timestamp, TICKS_PER_SECOND); - diff = diffTicks(last_timestamp_fixed, m_last_timestamp2); - if(diff-ticks_per_packet < 50 && diff-ticks_per_packet > -50) { - debugWarning("cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n", - CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2, - m_last_timestamp, diff, ticks_per_packet); - debugWarning("HACK: fixed by adding one second of ticks. This is a bug being run-time fixed.\n"); - m_last_timestamp = last_timestamp_fixed; - } else { - // if that didn't work, try to subtract one second - last_timestamp_fixed = substractTicks(m_last_timestamp, TICKS_PER_SECOND); - diff = diffTicks(last_timestamp_fixed, m_last_timestamp2); - if(diff-ticks_per_packet < 50 && diff-ticks_per_packet > -50) { - debugWarning("cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n", + + int ticks_per_packet = (int)(getTicksPerFrame() * getNominalFramesPerPacket()); + int diff = diffTicks(m_last_timestamp, m_last_timestamp2); + // display message if the difference between two successive tick + // values is more than 50 ticks. 1 sample at 48k is 512 ticks + // so 50 ticks = 10%, which is a rather large jitter value. + if(diff-ticks_per_packet > 50 || diff-ticks_per_packet < -50) { + debugOutput(DEBUG_LEVEL_VERBOSE, + "cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n", CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2, m_last_timestamp, diff, ticks_per_packet); - debugWarning("HACK: fixed by subtracing one second of ticks. This is a bug being run-time fixed.\n"); - m_last_timestamp = last_timestamp_fixed; + // !!!HACK!!! FIXME: this is the result of a failure in wrapping/unwrapping somewhere + // it's definitely a bug. + // try to fix up the timestamp + int64_t last_timestamp_fixed; + // first try to add one second + last_timestamp_fixed = addTicks(m_last_timestamp, TICKS_PER_SECOND); + diff = diffTicks(last_timestamp_fixed, m_last_timestamp2); + if(diff-ticks_per_packet < 50 && diff-ticks_per_packet > -50) { + debugWarning("cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n", + CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2, + m_last_timestamp, diff, ticks_per_packet); + debugWarning("HACK: fixed by adding one second of ticks. This is a bug being run-time fixed.\n"); + m_last_timestamp = last_timestamp_fixed; + } else { + // if that didn't work, try to subtract one second + last_timestamp_fixed = substractTicks(m_last_timestamp, TICKS_PER_SECOND); + diff = diffTicks(last_timestamp_fixed, m_last_timestamp2); + if(diff-ticks_per_packet < 50 && diff-ticks_per_packet > -50) { + debugWarning("cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n", + CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2, + m_last_timestamp, diff, ticks_per_packet); + debugWarning("HACK: fixed by subtracing one second of ticks. This is a bug being run-time fixed.\n"); + m_last_timestamp = last_timestamp_fixed; + } + } } - } - } - debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, - "%04u %011llu %011llu %d %d\n", - CYCLE_TIMER_GET_CYCLES(pkt_ctr), - m_last_timestamp2, m_last_timestamp, - diff, ticks_per_packet); -// #endif + debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, + "%04u %011llu %011llu %d %d\n", + CYCLE_TIMER_GET_CYCLES(pkt_ctr), + m_last_timestamp2, m_last_timestamp, + diff, ticks_per_packet); + } + #endif debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, @@ -723,4 +732,6 @@ debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "Nom fs: %12f, Instantanous fs: %12f, diff: %12f (%12f)\n", fs_nom, fs_syt, fs_diff, fs_diff_norm); +// debugOutput(DEBUG_LEVEL_VERBOSE, "Diff fs: %12f, m_last_timestamp: %011llu, m_last_timestamp2: %011llu\n", +// fs_diff, m_last_timestamp, m_last_timestamp2); if (fs_diff_norm > 0.01 || fs_diff_norm < -0.01) { debugWarning( "Instantanous samplerate more than 1%% off nominal. [Nom fs: %12f, Instantanous fs: %12f, diff: %12f (%12f)]\n", @@ -1551,5 +1562,6 @@ ringbuffer_size_frames += syncdelay_in_frames; - debugOutput(DEBUG_LEVEL_VERBOSE, "Prefill transmit SP %p with %u frames\n", this, ringbuffer_size_frames); + debugOutput(DEBUG_LEVEL_VERBOSE, "Prefill transmit SP %p with %u frames (sync_delay_frames = %d)\n", + this, ringbuffer_size_frames, syncdelay_in_frames); // prefill the buffer if(!transferSilence(ringbuffer_size_frames)) { Index: /branches/libffado-2.0/src/libutil/TimestampedBuffer.h =================================================================== --- /branches/libffado-2.0/src/libutil/TimestampedBuffer.h (revision 1525) +++ /branches/libffado-2.0/src/libutil/TimestampedBuffer.h (revision 1530) @@ -31,6 +31,9 @@ //typedef float ffado_timestamp_t; //#define TIMESTAMP_FORMAT_SPEC "%14.3f" + typedef double ffado_timestamp_t; #define TIMESTAMP_FORMAT_SPEC "%14.3f" +#define TIMESTAMP_MAX 3145728000.0 + // typedef int64_t ffado_timestamp_t; // #define TIMESTAMP_FORMAT_SPEC "%012lld" Index: /branches/libffado-2.0/src/libutil/TimestampedBuffer.cpp =================================================================== --- /branches/libffado-2.0/src/libutil/TimestampedBuffer.cpp (revision 1529) +++ /branches/libffado-2.0/src/libutil/TimestampedBuffer.cpp (revision 1530) @@ -58,4 +58,5 @@ pthread_mutex_unlock(&m_framecounter_lock); \ } + namespace Util { @@ -71,6 +72,6 @@ m_wrap_at(0xFFFFFFFFFFFFFFFFLLU), m_Client(c), m_framecounter(0), - m_buffer_tail_timestamp(0.0), - m_buffer_next_tail_timestamp(0.0), + m_buffer_tail_timestamp(TIMESTAMP_MAX + 1.0), + m_buffer_next_tail_timestamp(TIMESTAMP_MAX + 1.0), m_dll_e2(0.0), m_dll_b(DLL_COEFF_B), m_dll_c(DLL_COEFF_C), m_nominal_rate(0.0), m_current_rate(0.0), m_update_period(0) @@ -202,5 +203,6 @@ ENTER_CRITICAL_SECTION; - m_dll_e2 = m_update_period * (double)rate; + m_current_rate = rate; + m_dll_e2 = m_update_period * m_current_rate; m_buffer_next_tail_timestamp = (ffado_timestamp_t)((double)m_buffer_tail_timestamp + m_dll_e2); @@ -331,5 +333,5 @@ * * Resets the TimestampedBuffer, clearing the buffers and counters. - * Also resets the DLL to the nominal values. + * [DEL Also resets the DLL to the nominal values. DEL] * * \note when this is called, you should make sure that the buffer @@ -344,7 +346,5 @@ m_current_rate = m_nominal_rate; - m_dll_e2=m_nominal_rate * (float)m_update_period; - // this will init the internal timestamps to a sensible value - setBufferTailTimestamp(m_buffer_tail_timestamp); + m_dll_e2 = m_current_rate * (float)m_update_period; return true; @@ -402,8 +402,10 @@ // init the DLL - m_dll_e2=m_nominal_rate * (float)m_update_period; - - // this will init the internal timestamps to a sensible value - setBufferTailTimestamp(m_buffer_tail_timestamp); + m_dll_e2 = m_nominal_rate * (float)m_update_period; + + // init the timestamps to a bogus value, as there is not + // really something sane to say about them + m_buffer_tail_timestamp = TIMESTAMP_MAX + 1.0; + m_buffer_next_tail_timestamp = TIMESTAMP_MAX + 1.0; return true; @@ -462,6 +464,8 @@ // while disabled, we don't update the DLL, nor do we write frames // we just set the correct timestamp for the frames - incrementFrameCounter(nframes, ts); - decrementFrameCounter(nframes); + if (m_buffer_tail_timestamp < TIMESTAMP_MAX && m_buffer_next_tail_timestamp < TIMESTAMP_MAX) { + incrementFrameCounter(nframes, ts); + decrementFrameCounter(nframes); + } setBufferTailTimestamp(ts); } else { @@ -502,5 +506,5 @@ return false; } - + // make sure the head timestamp remains identical signed int fc; @@ -845,5 +849,5 @@ #ifdef DEBUG if (new_timestamp >= m_wrap_at) { - debugWarning("timestamp not wrapped: "TIMESTAMP_FORMAT_SPEC"\n",new_timestamp); + debugWarning("timestamp not wrapped: "TIMESTAMP_FORMAT_SPEC"\n", new_timestamp); } #endif @@ -854,5 +858,5 @@ // add the time - ts += (ffado_timestamp_t)(m_nominal_rate * (float)m_framecounter); + ts += (ffado_timestamp_t)(m_current_rate * (float)(m_framecounter)); if (ts >= m_wrap_at) { @@ -864,5 +868,5 @@ m_buffer_tail_timestamp = ts; - m_dll_e2=m_update_period * (double)m_nominal_rate; + m_dll_e2 = m_update_period * (double)m_current_rate; m_buffer_next_tail_timestamp = (ffado_timestamp_t)((double)m_buffer_tail_timestamp + m_dll_e2); @@ -949,5 +953,5 @@ ffado_timestamp_t retval; ENTER_CRITICAL_SECTION; - retval = getTimestampFromTail(m_framecounter-nframes); + retval = getTimestampFromTail(m_framecounter - nframes); EXIT_CRITICAL_SECTION; return retval; @@ -1103,5 +1107,5 @@ debugOutputShort( DEBUG_LEVEL_NORMAL, " Timestamps : head: "TIMESTAMP_FORMAT_SPEC", Tail: "TIMESTAMP_FORMAT_SPEC", Next tail: "TIMESTAMP_FORMAT_SPEC"\n", ts_head, m_buffer_tail_timestamp, m_buffer_next_tail_timestamp); - debugOutputShort( DEBUG_LEVEL_NORMAL, " Head - Tail : "TIMESTAMP_FORMAT_SPEC"\n", diff); + debugOutputShort( DEBUG_LEVEL_NORMAL, " Head - Tail : "TIMESTAMP_FORMAT_SPEC" (%f frames)\n", diff, diff/m_dll_e2*m_update_period); debugOutputShort( DEBUG_LEVEL_NORMAL, " DLL Rate : %f (%f)\n", m_dll_e2, m_dll_e2/m_update_period); debugOutputShort( DEBUG_LEVEL_NORMAL, " DLL Bandwidth : %10e 1/ticks (%f Hz)\n", getBandwidth(), getBandwidth() * TICKS_PER_SECOND);