Playback drift - adjusting Desired_fill

common.c

@@ -35,6 +35,7 @@
 #include <openssl/buffer.h>
 #include "common.h"
 #include "daemon.h"
+#include <time.h>
 
 shairport_cfg config;
 
@@ -57,7 +58,10 @@ void die(char *format, ...) {
 }
 
 void warn(char *format, ...) {
-    fprintf(stderr, "WARNING: ");
+    time_t rawtime;
+
+    time( &rawtime);
+    fprintf(stderr,  "%s WARNING: ", strtok(ctime(&rawtime),"\n"));
     va_list args;
     va_start(args, format);
     vfprintf(stderr, format, args);
@@ -66,8 +70,12 @@ void warn(char *format, ...) {
 }
 
 void debug(int level, char *format, ...) {
+    time_t rawtime;
     if (level > debuglev)
         return;
+
+    time( &rawtime);
+    fprintf(stderr,  "%s DEBUG: ", strtok(ctime(&rawtime),"\n"));
     va_list args;
     va_start(args, format);
     vfprintf(stderr, format, args);

configure

@@ -6,7 +6,7 @@ rm -f config.mk config.h
 
 echo "// automatically generated file" > config.h
 
-LDFLAGS="${LDFLAGS} -lm -lpthread"
+LDFLAGS="${LDFLAGS} -lm -lpthread -lwiringPi"
 
 export_config()
 {

player.c

@@ -100,6 +100,17 @@ static void ab_resync(void) {
     ab_buffering = 1;
 }
 
+// reset the audio frames in the range to NOT ready
+static void ab_reset(seq_t from, seq_t to) {
+    abuf_t *abuf = 0;
+
+    while (seq_diff(from, to)) {
+	abuf = audio_buffer + BUFIDX(from);
+	abuf->ready = 0;
+	from++;
+    }
+}
+
 // the sequence numbers will wrap pretty often.
 // this returns true if the second arg is after the first
 static inline int seq_order(seq_t a, seq_t b) {
@@ -188,13 +199,28 @@ static void free_buffer(void) {
         free(audio_buffer[i].data);
 }
 
+    //  Calculate the boundary threshold for resends dependant on buffer size
+    //  FOCUS_BOUNDARY is the preferred threshold if this can be accomodated
+    //  Resends are typically handled as a result of advance packets
+    //  However below the boundary resends are also handled in Last-Chance algorithm
+#define FOCUS_BOUNDARY  128
+
+static int resend_focus(int fill){
+    if ((fill > FOCUS_BOUNDARY) &&
+        ((fill/2) < FOCUS_BOUNDARY)) {
+	return FOCUS_BOUNDARY;
+    } else {
+	return (fill/2);
+    }
+}
+
 void player_put_packet(seq_t seqno, uint8_t *data, int len) {
     abuf_t *abuf = 0;
     int16_t buf_fill;
 
     pthread_mutex_lock(&ab_mutex);
     if (!ab_synced) {
-        debug(2, "syncing to first seqno %04X\n", seqno);
+        debug(1, "syncing to first seqno %04X\n", seqno);
         ab_write = seqno-1;
         ab_read = seqno;
         ab_synced = 1;
@@ -203,13 +229,32 @@ void player_put_packet(seq_t seqno, uint8_t *data, int len) {
         abuf = audio_buffer + BUFIDX(seqno);
         ab_write = seqno;
     } else if (seq_order(ab_write, seqno)) {    // newer than expected
-        rtp_request_resend(ab_write+1, seqno-1);
-        abuf = audio_buffer + BUFIDX(seqno);
-        ab_write = seqno;
+	// Be careful with new packets that are in advance
+	// Those more than a buffer size in advance will cause an Overrun
+	// When buffering the valid threshold should be the buffer fill target itself which should re-sync
+	if (ab_buffering && (seq_diff(ab_read, seqno) > config.buffer_start_fill)) {
+	   warn("out of range re-sync %04X (%04X:%04X)", seqno, ab_read, ab_write);
+	   ab_resync();
+	   ab_synced = 1;
+	   ab_read = seqno;
+	   ab_write = seqno;
+           abuf = audio_buffer + BUFIDX(seqno);
+	} else {
+           debug(1, "advance packet %04X (%04X:%04X)\n", seqno, ab_read, ab_write);
+
+           rtp_request_resend(ab_write+1, seqno-1);
+
+           abuf = audio_buffer + BUFIDX(seqno);
+           ab_write = seqno;
+	}
     } else if (seq_order(ab_read, seqno)) {     // late but not yet played
         abuf = audio_buffer + BUFIDX(seqno);
+	if (abuf->ready) {			// discard this frame if frame previously received
+	   abuf =0;
+           debug(1, "duplicate packet %04X (%04X:%04X)\n", seqno, ab_read, ab_write);
+	}
     } else {    // too late.
-        debug(1, "late packet %04X (%04X:%04X)", seqno, ab_read, ab_write);
+        debug(1, "late packet %04X (%04X:%04X)\n", seqno, ab_read, ab_write);
     }
     buf_fill = seq_diff(ab_read, ab_write);
     pthread_mutex_unlock(&ab_mutex);
@@ -221,9 +266,8 @@ void player_put_packet(seq_t seqno, uint8_t *data, int len) {
 
     pthread_mutex_lock(&ab_mutex);
     if (ab_buffering && buf_fill >= config.buffer_start_fill) {
-        debug(1, "buffering over. starting play\n");
+        debug(1, "buffering over. starting play (%04X:%04X)\n", ab_read, ab_write);
         ab_buffering = 0;
-        bf_est_reset(buf_fill);
     }
     pthread_mutex_unlock(&ab_mutex);
 }
@@ -315,9 +359,10 @@ static void bf_est_update(short fill) {
         return;
     } else if (fill_count == 1000) {
         // this information could be used to help estimate our effective latency?
+	desired_fill = (2*config.buffer_start_fill) - desired_fill;
         debug(1, "established desired fill of %f frames, "
               "so output chain buffered about %f frames\n", desired_fill,
-              config.buffer_start_fill - desired_fill);
+              desired_fill - config.buffer_start_fill);
         fill_count++;
     }
 
@@ -353,35 +398,38 @@ static short *buffer_get_frame(void) {
     buf_fill = seq_diff(ab_read, ab_write);
     if (buf_fill < 1 || !ab_synced) {
         if (buf_fill < 1)
-            warn("underrun.");
-        ab_buffering = 1;
+            warn("underrun %i (%04X:%04X)", buf_fill, ab_read, ab_write);
+	ab_resync();
         pthread_mutex_unlock(&ab_mutex);
         return 0;
     }
     if (buf_fill >= BUFFER_FRAMES) {   // overrunning! uh-oh. restart at a sane distance
-        warn("overrun.");
+        warn("overrun %i (%04X:%04X)", buf_fill, ab_read, ab_write);
+	read = ab_read;
         ab_read = ab_write - config.buffer_start_fill;
+	ab_reset((ab_write + 1 - BUFFER_FRAMES), ab_read);	// reset any ready frames in those we've skipped (avoiding wrap around)
     }
     read = ab_read;
     ab_read++;
     buf_fill = seq_diff(ab_read, ab_write);
     bf_est_update(buf_fill);
 
-    // check if t+16, t+32, t+64, t+128, ... (buffer_start_fill / 2)
+    // check if t+16, t+32, t+64, t+128, ... resend focus boundary
     // packets have arrived... last-chance resend
     if (!ab_buffering) {
-        for (i = 16; i < (config.buffer_start_fill / 2); i = (i * 2)) {
+        for (i = 16; i <= resend_focus(config.buffer_start_fill); i = (i * 2)) {
             next = ab_read + i;
             abuf = audio_buffer + BUFIDX(next);
-            if (!abuf->ready) {
+            if ((!abuf->ready) && (next < ab_write)){
                 rtp_request_resend(next, next);
+                debug(1, "last chance resend T+%i, %04X (%04X:%04X)\n", i, next, ab_read, ab_write);
             }
         }
     }
 
     abuf_t *curframe = audio_buffer + BUFIDX(read);
     if (!curframe->ready) {
-        debug(1, "missing frame %04X.", read);
+        debug(1, "missing frame %04X\n", read);
         memset(curframe->data, 0, FRAME_BYTES(frame_size));
     }
     curframe->ready = 0;
@@ -514,6 +562,7 @@ int player_play(stream_cfg *stream) {
 #ifdef FANCY_RESAMPLING
     init_src();
 #endif
+    bf_est_reset(config.buffer_start_fill);		// initialise frame matching algorithm - only once per read thread (semaphore not required at this point)
 
     please_stop = 0;
     command_start();

rtp.c

@@ -179,7 +179,7 @@ void rtp_request_resend(seq_t first, seq_t last) {
     if (!running)
         die("rtp_request_resend called without active stream!");
 
-    debug(1, "requesting resend on %d packets (%04X:%04X)\n",
+    debug(2, "requesting resend on %d packets (%04X:%04X)\n",
          seq_diff(first,last) + 1, first, last);
 
     char req[8];    // *not* a standard RTCP NACK

rtsp.c

@@ -45,6 +45,7 @@
 #include "player.h"
 #include "rtp.h"
 #include "mdns.h"
+#include "wiringPi.h"
 
 #ifdef AF_INET6
 #define INETx_ADDRSTRLEN INET6_ADDRSTRLEN
@@ -372,6 +373,7 @@ static void handle_teardown(rtsp_conn_info *conn,
                             rtsp_message *req, rtsp_message *resp) {
     if (!rtsp_playing())
         return;
+    digitalWrite(11, 1);	/* On TearDown:	Turn Ampliefier OFF - enable sleep */
     resp->respcode = 200;
     msg_add_header(resp, "Connection", "close");
     please_shutdown = 1;
@@ -409,6 +411,7 @@ static void handle_setup(rtsp_conn_info *conn,
     int sport = rtp_setup(&conn->remote, cport, tport);
     if (!sport)
         return;
+    digitalWrite(11, 0);	/* On Set-up:	Turn Amplifier ON - disable sleep */
 
     player_play(&conn->stream);
 
@@ -816,6 +819,10 @@ void rtsp_listen_loop(void) {
             maxfd = sockfd[i];
     }
 
+    wiringPiSetupPhys();	/* Listen Loop: Initilise the GPIO access - use physical pin numbers */
+    pinMode(11, OUTPUT);	/* let's use Pin 11 */
+    digitalWrite(11, 1);	/* turn Amplifier Sleep mode ON */
+
     mdns_register();
 
     printf("Listening for connections.\n");