Add check of drift in the source material -- i,e, divergence between …

…calculated and actual remote clocks for frames.

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);

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

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);
 }
 

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;