From 841014277e0ea44919f21913b823df2dda1eb576 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 26 Jun 2015 15:11:21 +0100 Subject: [PATCH] Add check of drift in the source material -- i,e, divergence between calculated and actual remote clocks for frames. --- common.h | 2 ++ player.c | 23 +++++++++++++---------- rtp.c | 42 +++++++++++++++++++++++++++++++----------- rtp.h | 2 +- 4 files changed, 47 insertions(+), 22 deletions(-) diff --git a/common.h b/common.h index 6b38442d..22de06d2 100644 --- a/common.h +++ b/common.h @@ -121,6 +121,8 @@ shairport_cfg config; config_t config_file_stuff; int64_t session_corrections; +uint32_t play_segment_reference_frame; +uint64_t play_segment_reference_frame_remote_time; void command_start(void); void command_stop(void); diff --git a/player.c b/player.c index 47f9b27c..f423ff04 100644 --- a/player.c +++ b/player.c @@ -492,8 +492,8 @@ static abuf_t *buffer_get_frame(void) { // debug(1,"First frame seen, time %u, with %d // frames...",curframe->timestamp,seq_diff(ab_read, ab_write)); uint32_t reference_timestamp; - uint64_t reference_timestamp_time; - get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time); + uint64_t reference_timestamp_time,remote_reference_timestamp_time; + get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time); if (reference_timestamp) { // if we have a reference time // debug(1,"First frame seen with timestamp..."); first_packet_timestamp = curframe->timestamp; // we will keep buffering until we are @@ -601,12 +601,13 @@ static abuf_t *buffer_get_frame(void) { // with %d packets.",exact_frame_gap,fs,dac_delay,seq_diff(ab_read, ab_write)); config.output->play(silence, fs); free(silence); -#ifdef CONFIG_METADATA if (ab_buffering == 0) { - send_ssnc_metadata('prsm', NULL, 0, - 0); // "resume", but don't wait if the queue is locked - } + uint64_t reference_timestamp_time; // don't need this... + get_reference_timestamp_stuff(&play_segment_reference_frame, &reference_timestamp_time, &play_segment_reference_frame_remote_time); +#ifdef CONFIG_METADATA + send_ssnc_metadata('prsm', NULL, 0, 0); // "resume", but don't wait if the queue is locked #endif + } } } } @@ -629,8 +630,8 @@ static abuf_t *buffer_get_frame(void) { int do_wait = 1; if ((ab_synced) && (curframe) && (curframe->ready) && (curframe->timestamp)) { uint32_t reference_timestamp; - uint64_t reference_timestamp_time; - get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time); + uint64_t reference_timestamp_time,remote_reference_timestamp_time; + get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time); if (reference_timestamp) { // if we have a reference time uint32_t packet_timestamp = curframe->timestamp; int64_t delta = ((int64_t)packet_timestamp - (int64_t)reference_timestamp); @@ -856,6 +857,7 @@ typedef struct stats { // statistics for running averages static void *player_thread_func(void *arg) { session_corrections = 0; + play_segment_reference_frame = 0; // zero signals that we are not in a play segment // check that there are enough buffers to accommodate the desired latency and the latency offset int maximum_latency = config.latency+config.audio_backend_latency_offset; @@ -924,8 +926,8 @@ static void *player_thread_func(void *arg) { at_least_one_frame_seen = 1; uint32_t reference_timestamp; - uint64_t reference_timestamp_time; - get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time); + uint64_t reference_timestamp_time,remote_reference_timestamp_time; + get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time); int64_t rt, nt; rt = reference_timestamp; @@ -1232,6 +1234,7 @@ void player_flush(uint32_t timestamp) { // if (timestamp!=0) flush_rtp_timestamp = timestamp; // flush all packets up to (and including?) this pthread_mutex_unlock(&flush_mutex); + play_segment_reference_frame = 0; #ifdef CONFIG_METADATA send_ssnc_metadata('pfls', NULL, 0, 1); #endif diff --git a/rtp.c b/rtp.c index d6a0eab7..b4026a47 100644 --- a/rtp.c +++ b/rtp.c @@ -68,6 +68,7 @@ static pthread_t rtp_audio_thread, rtp_control_thread, rtp_timing_thread; static uint32_t reference_timestamp; static uint64_t reference_timestamp_time; +static uint64_t remote_reference_timestamp_time; // debug variables static int request_sent; @@ -199,12 +200,13 @@ static void *rtp_control_receiver(void *arg) { // after the one whose RTP is given. Weird. } pthread_mutex_lock(&reference_time_mutex); + remote_reference_timestamp_time = remote_time_of_sync; reference_timestamp_time = remote_time_of_sync - local_to_remote_time_difference; reference_timestamp = sync_rtp_timestamp; pthread_mutex_unlock(&reference_time_mutex); // debug(1,"New Reference timestamp and timestamp time..."); // get estimated remote time now - remote_time_now = local_time_now + local_to_remote_time_difference; + // remote_time_now = local_time_now + local_to_remote_time_difference; // debug(1,"Sync Time is %lld us late (remote // times).",((remote_time_now-remote_time_of_sync)*1000000)>>32); @@ -404,23 +406,40 @@ static void *rtp_timing_receiver(void *arg) { first_local_to_remote_time_difference = local_to_remote_time_difference; first_local_to_remote_time_difference_time = get_absolute_time_in_fp(); } + + int64_t source_drift_usec; + if (play_segment_reference_frame!=0) { + uint32_t reference_timestamp; + uint64_t reference_timestamp_time,remote_reference_timestamp_time; + get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time); + uint64_t frame_difference = 0; + if (reference_timestamp>=play_segment_reference_frame) + frame_difference = (uint64_t)reference_timestamp-(uint64_t)play_segment_reference_frame; + else // rollover + frame_difference = (uint64_t)reference_timestamp+0x100000000-(uint64_t)play_segment_reference_frame; + uint64_t frame_time_difference_calculated = (((uint64_t)frame_difference<<32)/44100); + uint64_t frame_time_difference_specified = remote_reference_timestamp_time-play_segment_reference_frame_remote_time; + // debug(1,"%llu frames since play started, %llu usec calculated, %llu usec actual",frame_difference, (frame_time_difference_calculated*1000000)>>32, (frame_time_difference_specified*1000000)>>32); + if (frame_time_difference_specified>=frame_time_difference_calculated) + source_drift_usec = frame_time_difference_specified-frame_time_difference_calculated; + else + source_drift_usec = -(frame_time_difference_calculated-frame_time_difference_specified); + } else + source_drift_usec = 0; + source_drift_usec = (source_drift_usec*1000000)>>32; // turn it to microseconds uint64_t clock_drift; int64_t current_delay; -// if (config.output->delay) { -// current_delay = config.output->delay(); -// } + if (config.output->delay) { + current_delay = config.output->delay(); + } if (first_local_to_remote_time_difference>=local_to_remote_time_difference) { clock_drift = ((first_local_to_remote_time_difference - local_to_remote_time_difference) * 1000000)>>32; -// debug(1, "-%llu\t%lld\t%lld", clock_drift,(session_corrections*1000000)/44100,current_delay); - debug(1, "-%llu\t%lld", clock_drift,(session_corrections*1000000)/44100); - //debug(1,"Clock drift is -%lld usec.",clock_drift); + debug(1, "-%llu\t%lld\t%lld\t%lld", clock_drift,(session_corrections*1000000)/44100,current_delay,source_drift_usec); } else { clock_drift = ((local_to_remote_time_difference - first_local_to_remote_time_difference) * 1000000) >>32; - //debug(1,"Clock drift is %lld usec.",clock_drift); -// debug(1, "%llu\t%lld\t%lld", clock_drift,(session_corrections*1000000)/44100,current_delay); - debug(1, "%llu\t%lld\t", clock_drift,(session_corrections*1000000)/44100); + debug(1, "%llu\t%lld\t%lld\t%lld", clock_drift,(session_corrections*1000000)/44100,current_delay,source_drift_usec); } } else { @@ -581,10 +600,11 @@ void rtp_setup(SOCKADDR *remote, int cport, int tport, uint32_t active_remote, i request_sent = 0; } -void get_reference_timestamp_stuff(uint32_t *timestamp, uint64_t *timestamp_time) { +void get_reference_timestamp_stuff(uint32_t *timestamp, uint64_t *timestamp_time, uint64_t *remote_timestamp_time) { pthread_mutex_lock(&reference_time_mutex); *timestamp = reference_timestamp; *timestamp_time = reference_timestamp_time; + *remote_timestamp_time = remote_reference_timestamp_time; pthread_mutex_unlock(&reference_time_mutex); } diff --git a/rtp.h b/rtp.h index 5fd67983..8045d2bb 100644 --- a/rtp.h +++ b/rtp.h @@ -11,7 +11,7 @@ void rtp_shutdown(void); void rtp_request_resend(seq_t first, uint32_t count); void rtp_request_client_pause(void); // ask the client to pause -void get_reference_timestamp_stuff(uint32_t *timestamp, uint64_t *timestamp_time); +void get_reference_timestamp_stuff(uint32_t *timestamp, uint64_t *timestamp_time, uint64_t *remote_timestamp_time); void clear_reference_timestamp(void); uint64_t static local_to_remote_time_jitters;