]> git.ipfire.org Git - thirdparty/shairport-sync.git/commitdiff
Add missing frame status field, fix a bug with the first missing frame variable,...
authorMike Brady <mikebrady@eircom.net>
Thu, 10 Oct 2019 08:23:20 +0000 (09:23 +0100)
committerMike Brady <mikebrady@eircom.net>
Thu, 10 Oct 2019 08:23:20 +0000 (09:23 +0100)
common.c
common.h
player.c
player.h
rtp.c
rtsp.c
scripts/shairport-sync.conf
shairport.c

index 2cadc20313cceeca79f24c6497de4b4532c43747..ff643ef38b1c29ea4e97c20237da991aebc2cc67 100644 (file)
--- a/common.c
+++ b/common.c
@@ -1299,6 +1299,7 @@ int _debug_mutex_unlock(pthread_mutex_t *mutex, const char *mutexname, const cha
 void malloc_cleanup(void *arg) {
   // debug(1, "malloc cleanup called.");
   free(arg);
+  arg = NULL;
 }
 
 void pthread_cleanup_debug_mutex_unlock(void *arg) { pthread_mutex_unlock((pthread_mutex_t *)arg); }
index f05f107e5c5d50cbb0eb1f14ef7d44e4848d0b64..b50d4844efd670d35363b9bcef3e31c1ceb71616 100644 (file)
--- a/common.h
+++ b/common.h
@@ -100,9 +100,9 @@ enum sps_format_t {
 const char *sps_format_description_string(enum sps_format_t format);
 
 typedef struct {
-  double resend_wait_before_check; // wait this long before asking for a missing packet to be resent
-  double resend_wait_between_checks; // wait this long between making requests
-  double resend_last_check_before_use; // if the packet is missing this close to the time of use, give up
+  double resend_control_first_check_time; // wait this long before asking for a missing packet to be resent
+  double resend_control_check_interval_time; // wait this long between making requests
+  double resend_control_last_check_time; // if the packet is missing this close to the time of use, give up
   pthread_mutex_t lock;
   config_t *cfg;
   int endianness;
index 31098598702dc688971845dc0ae6c893e9ef347a..e98331f4d8ebf3d458d5aa656ebd0fcf90135bea 100644 (file)
--- a/player.c
+++ b/player.c
@@ -139,7 +139,7 @@ static void ab_resync(rtsp_conn_info *conn) {
 int position_in_modulo_uint16_t_buffer(uint16_t x, uint16_t start, uint16_t end, uint16_t *pos) {
   int response = 0; // not in the buffer
   if (start <= end) {
-    if (x < start) {
+    if (x < start) { // this means that it's up around the wrap
       if (pos)
         *pos = UINT16_MAX - start + 1 + x;
     } else {
@@ -483,7 +483,6 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
   conn->packet_count_since_flush++;
   conn->time_of_last_audio_packet = time_now;
   if (conn->connection_state_to_output) { // if we are supposed to be processing these packets
-
     if ((conn->flush_rtp_timestamp != 0) && (actual_timestamp != conn->flush_rtp_timestamp) &&
         (modulo_32_offset(actual_timestamp, conn->flush_rtp_timestamp) <
          conn->input_rate * 10)) { // if it's less than 10 seconds
@@ -494,19 +493,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
       conn->initial_reference_time = 0;
       conn->initial_reference_timestamp = 0;
     } else {
-      /*
-        if ((conn->flush_rtp_timestamp != 0) &&
-            (modulo_32_offset(conn->flush_rtp_timestamp, actual_timestamp) > conn->input_rate / 5)
-        &&
-            (modulo_32_offset(conn->flush_rtp_timestamp, actual_timestamp) < conn->input_rate)) {
-          // between 0.2 and 1 second
-          debug(2, "Dropping flush request in player_put_packet");
-          conn->flush_rtp_timestamp = 0;
-        }
-      */
-
       abuf_t *abuf = 0;
-
       if (!conn->ab_synced) {
         // if this is the first packet...
         debug(3, "syncing to seqno %u.", seqno);
@@ -514,21 +501,6 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
         conn->ab_read = seqno;
         conn->ab_synced = 1;
       }
-
-      // here, we should check for missing frames
-      int resend_interval = (((250 * 44100) / 352) / 1000); // approximately 250 ms intervals
-      const int number_of_resend_attempts = 8;
-      int latency_based_resend_interval =
-          (conn->latency) / (number_of_resend_attempts * conn->max_frames_per_packet);
-      if (latency_based_resend_interval > resend_interval)
-        resend_interval = latency_based_resend_interval;
-
-      if (conn->resend_interval != resend_interval) {
-        debug(2, "Resend interval for latency of %u frames is %d frames.", conn->latency,
-              resend_interval);
-        conn->resend_interval = resend_interval;
-      }
-
       if (conn->ab_write ==
           seqno) { // if this is the expected packet (which could be the first packet...)
         if (conn->input_frame_rate_starting_point_is_valid == 0) {
@@ -538,17 +510,11 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
             conn->input_frame_rate_starting_point_is_valid = 1; // valid now
           }
         }
-
         conn->frames_inward_measurement_time = time_now;
         conn->frames_inward_frames_received_at_measurement_time = actual_timestamp;
-
         abuf = conn->audio_buffer + BUFIDX(seqno);
         conn->ab_write = SUCCESSOR(seqno); // move the write pointer to the next free space
       } else if (seq_order(conn->ab_write, seqno, conn->ab_read)) { // newer than expected
-        // if (ORDINATE(seqno)>(BUFFER_FRAMES*7)/8)
-        // debug(1,"An interval of %u frames has opened, with ab_read: %u, ab_write: %u and
-        // seqno:
-        // %u.",seq_diff(ab_read,seqno),ab_read,ab_write,seqno);
         int32_t gap = seq_diff(conn->ab_write, seqno, conn->ab_read);
         if (gap <= 0)
           debug(1, "Unexpected gap size: %d.", gap);
@@ -558,6 +524,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
           abuf->ready = 0; // to be sure, to be sure
           abuf->resend_request_number = 0;
           abuf->initialisation_time = time_now; // this represents when the packet was noticed to be missing
+          abuf->status = 1 << 0; // signifying missing
           abuf->resend_time = 0;
           abuf->given_timestamp = 0;
           abuf->sequence_number = 0;
@@ -567,24 +534,12 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
         //        rtp_request_resend(ab_write, gap);
         //        resend_requests++;
         conn->ab_write = SUCCESSOR(seqno);
-      } else if (seq_order(conn->ab_read, seqno, conn->ab_read)) { // late but not yet played
+      } else if (seq_order(conn->ab_read, seqno, conn->ab_read)) { // older than expected but not too late
         conn->late_packets++;
         abuf = conn->audio_buffer + BUFIDX(seqno);
-        /*
-        if (abuf->ready)
-                debug(1,"Late apparently duplicate packet received that is %d packets
-        late.",seq_diff(seqno, conn->ab_write, conn->ab_read));
-        else
-                debug(1,"Late packet received that is %d packets late.",seq_diff(seqno,
-        conn->ab_write, conn->ab_read));
-              */
       } else { // too late.
-
-        // debug(1,"Too late packet received that is %d packets late.",seq_diff(seqno,
-        // conn->ab_write, conn->ab_read));
         conn->too_late_packets++;
       }
-      // pthread_mutex_unlock(&ab_mutex);
 
       if (abuf) {
         int datalen = conn->max_frames_per_packet;
@@ -592,28 +547,29 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
         abuf->resend_time = 0;
         if (audio_packet_decode(abuf->data, &datalen, data, len, conn) == 0) {
           abuf->ready = 1;
+          abuf->status = 0; // signifying that it was received
           abuf->length = datalen;
           abuf->given_timestamp = actual_timestamp;
           abuf->sequence_number = seqno;
         } else {
           debug(1, "Bad audio packet detected and discarded.");
           abuf->ready = 0;
+          abuf->status = 1 << 1; // bad packet, discarded
           abuf->resend_request_number = 0;
           abuf->given_timestamp = 0;
           abuf->sequence_number = 0;
         }
       }
 
-      // pthread_mutex_lock(&ab_mutex);
       int rc = pthread_cond_signal(&conn->flowcontrol);
       if (rc)
         debug(1, "Error signalling flowcontrol.");
       
       // resend checks
       {
-       uint64_t minimum_wait_time = (uint64_t)(config.resend_wait_before_check * (uint64_t)0x100000000);
-       uint64_t resend_repeat_interval = (uint64_t)(config.resend_wait_between_checks * (uint64_t)0x100000000);
-       uint64_t minimum_remaining_time = (uint64_t)((config.resend_last_check_before_use + config.audio_backend_buffer_desired_length)* (uint64_t)0x100000000);
+       uint64_t minimum_wait_time = (uint64_t)(config.resend_control_first_check_time * (uint64_t)0x100000000);
+       uint64_t resend_repeat_interval = (uint64_t)(config.resend_control_check_interval_time * (uint64_t)0x100000000);
+       uint64_t minimum_remaining_time = (uint64_t)((config.resend_control_last_check_time + config.audio_backend_buffer_desired_length)* (uint64_t)0x100000000);
        uint64_t latency_time = (uint64_t)(conn->latency * (uint64_t)0x100000000);
        latency_time = latency_time / (uint64_t)conn->input_rate;
                
@@ -624,19 +580,36 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
         } else {
           x = conn->ab_read;
         }
-      
+        
+        first_possibly_missing_frame = -1; // has not been set
+        
        int missing_frame_run_count = 0;
        int start_of_missing_frame_run = -1;
         int number_of_missing_frames = 0;
-        debug(3,"check start");
         while (x != conn->ab_write) {
           abuf_t *check_buf = conn->audio_buffer + BUFIDX(x);
           if (!check_buf->ready) {
+            if (first_possibly_missing_frame < 0)
+              first_possibly_missing_frame = x;
             number_of_missing_frames++;
             // debug(1, "frame %u's initialisation_time is 0x%" PRIx64 ", latency_time is 0x%" PRIx64 ", time_now is 0x%" PRIx64 ", minimum_remaining_time is 0x%" PRIx64 ".", x, check_buf->initialisation_time, latency_time, time_now, minimum_remaining_time);
             int too_late = ((check_buf->initialisation_time < (time_now - latency_time)) || ((check_buf->initialisation_time - (time_now - latency_time)) < minimum_remaining_time));
             int too_early = ((time_now - check_buf->initialisation_time) < minimum_wait_time);
             int too_soon_after_last_request = ((check_buf->resend_time != 0) && ((time_now - check_buf->resend_time) < resend_repeat_interval)); // time_now can never be less than the time_tag
+
+            if (too_late)
+              check_buf->status |= 1<<2; // too late
+            else
+              check_buf->status &= 0xFF-(1<<2); // not too late
+            if (too_early)
+              check_buf->status |= 1<<3; // too early
+            else
+              check_buf->status &= 0xFF-(1<<3); // not too early                            
+            if (too_soon_after_last_request)
+              check_buf->status |= 1<<4; // too soon after last request
+            else
+              check_buf->status &= 0xFF-(1<<4); // not too soon after last request
+                            
             if ((!too_soon_after_last_request) && (!too_late) && (!too_early)){
               if (start_of_missing_frame_run == -1) {
                 start_of_missing_frame_run = x;
@@ -646,7 +619,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
               }
               check_buf->resend_time = time_now; // setting the time to now because we are definitely going to take action
               check_buf->resend_request_number++;
-              debug(2,"Frame %d is missing with ab_read of %d.", x, conn->ab_read);            
+              debug(3,"Frame %d is missing with ab_read of %u and ab_write of %u.", x, conn->ab_read, conn->ab_write);            
             }
             // if (too_late) {
             //   debug(1,"too late to get missing frame %u.", x);
@@ -1992,8 +1965,8 @@ void *player_thread_func(void *arg) {
         //          debug(3, "Play frame %d.", play_number);
         conn->play_number_after_flush++;
         if (inframe->given_timestamp == 0) {
-          debug(2, "Player has supplied a silent frame, (possibly frame %u) for play number %d, after %d resend requests.",
-                SUCCESSOR(conn->last_seqno_read), play_number, inframe->resend_request_number);
+          debug(1, "Player has supplied a silent frame, (possibly frame %u) for play number %d, status 0x%X after %u resend requests.",
+                SUCCESSOR(conn->last_seqno_read), play_number, inframe->status, inframe->resend_request_number);
           conn->last_seqno_read = (SUCCESSOR(conn->last_seqno_read) &
                                    0xffff); // manage the packet out of sequence minder
 
index 0d89da4480090b180b1b3b3f2ccde2278dbea12c..9246f4485ba3318736bd5b0dc5b08630058dcd6a 100644 (file)
--- a/player.h
+++ b/player.h
@@ -38,13 +38,14 @@ typedef struct time_ping_record {
 typedef uint16_t seq_t;
 
 typedef struct audio_buffer_entry { // decoded audio packets
-  int ready;
+  uint8_t ready;
+  uint8_t status; // flags
+  uint16_t resend_request_number;
+  signed short *data;
+  seq_t sequence_number;
   uint64_t initialisation_time; // the time the packet was added or the time it was noticed the packet was missing
   uint64_t resend_time; // time of last resend request or zero
-  int resend_request_number;
-  seq_t sequence_number;
   uint32_t given_timestamp; // for debugging and checking
-  signed short *data;
   int length; // the length of the decoded data
 } abuf_t;
 
diff --git a/rtp.c b/rtp.c
index 2e1e7f9f43f942a8fe4b541d3f5f2422da0e5b46..6a90a5cda5dc200c795aae3ac615e8d6f42ba57e 100644 (file)
--- a/rtp.c
+++ b/rtp.c
@@ -1218,7 +1218,8 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) {
     }
 #endif
     uint64_t time_of_sending_fp = get_absolute_time_in_fp();
-    uint64_t resend_error_backoff_time = (uint64_t)1 << (32 - 4); // one sixteenth of a second
+    uint64_t resend_error_backoff_time = (uint64_t)1000000 * 0.3; // 0.3 seconds
+    resend_error_backoff_time = (resend_error_backoff_time << 32) / 1000000;
     if ((conn->rtp_time_of_last_resend_request_error_fp == 0) ||
         ((time_of_sending_fp - conn->rtp_time_of_last_resend_request_error_fp) >
          resend_error_backoff_time)) {
@@ -1238,8 +1239,7 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) {
                    (struct sockaddr *)&conn->rtp_client_control_socket, msgsize) == -1) {
           char em[1024];
           strerror_r(errno, em, sizeof(em));
-          debug(1, "Error %d using sendto to an audio socket: \"%s\". Backing off for 1/16th of a "
-                   "second.",
+          debug(2, "Error %d using sendto to request a resend: \"%s\".",
                 errno, em);
           conn->rtp_time_of_last_resend_request_error_fp = time_of_sending_fp;
         } else {
@@ -1249,12 +1249,12 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) {
       } else {
         debug(
             3,
-            "Dropping resend request packet to simulate a bad network. Backing off for 1/16th of a "
+            "Dropping resend request packet to simulate a bad network. Backing off for 0.3 "
             "second.");
         conn->rtp_time_of_last_resend_request_error_fp = time_of_sending_fp;
       }
     } else {
-      debug(3, "Backing off sending resend requests due to a previous send-to error");
+      debug(1, "Suppressing a resend request due to a resend sendto error in the last 0.3 seconds.");
     }
   } else {
     // if (!request_sent) {
diff --git a/rtsp.c b/rtsp.c
index 1b198c69c7c3a6dee09865820d710a6cccc4145f..ded7035f036089b03e01ac7c9d1fb9bc8045ca54 100644 (file)
--- a/rtsp.c
+++ b/rtsp.c
@@ -591,15 +591,6 @@ enum rtsp_read_request_response rtsp_read_request(rtsp_conn_info *conn, rtsp_mes
   int msg_size = -1;
 
   while (msg_size < 0) {
-    /*
-fd_set readfds;
-FD_ZERO(&readfds);
-FD_SET(conn->fd, &readfds);
-do {
-  memory_barrier();
-} while (conn->stop == 0 &&
-         pselect(conn->fd + 1, &readfds, NULL, NULL, NULL, &pselect_sigset) <= 0);
-*/
     if (conn->stop != 0) {
       debug(3, "RTSP conversation thread %d shutdown requested.", conn->connection_number);
       reply = rtsp_read_request_response_immediate_shutdown_requested;
@@ -684,16 +675,6 @@ do {
       }
     }
 
-    /*
-    fd_set readfds;
-    FD_ZERO(&readfds);
-    FD_SET(conn->fd, &readfds);
-    do {
-      memory_barrier();
-    } while (conn->stop == 0 &&
-             pselect(conn->fd + 1, &readfds, NULL, NULL, NULL, &pselect_sigset) <= 0);
-    */
-
     if (conn->stop != 0) {
       debug(1, "RTSP shutdown requested.");
       reply = rtsp_read_request_response_immediate_shutdown_requested;
@@ -711,8 +692,17 @@ do {
     if (nread < 0) {
       if (errno == EINTR)
         continue;
-      perror("read failure");
-      reply = rtsp_read_request_response_error;
+      if (errno == EAGAIN) {
+        debug(1, "Getting Error 11 -- EAGAIN from a blocking read!");
+        continue;
+      }
+      if (errno != ECONNRESET) {
+        char errorstring[1024];
+        strerror_r(errno, (char *)errorstring, sizeof(errorstring));
+        debug(1, "Connection %d: rtsp_read_request_response_read_error %d: \"%s\".",
+              conn->connection_number, errno, (char *)errorstring);
+      }
+      reply = rtsp_read_request_response_read_error;
       goto shutdown;
     }
     inbuf += nread;
index 6bca6d0e1b079583f071ee0fc92ab7ea9ff573be..54e22e878374d66dc2c0a42480a62070b83a62eb 100644 (file)
@@ -51,6 +51,10 @@ general =
 //             as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session".
 //     mpris_service_bus = "system"; // The Shairport Sync mpris interface, if selected at compilation, will appear
 //             as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session".
+//     resend_control_first_check_time = 0.10; // Use this optional advanced setting to set the wait time in seconds before deciding a packet is missing.
+//     resend_control_check_interval_time = 0.25; //  Use this optional advanced setting to set the time in seconds between requests for a missing packet.
+//     resend_control_last_check_time = 0.10; // Use this optional advanced setting to set the latest time, in seconds, by which the last check should be done before the estimated time of a missing packet's transfer to the output buffer.
+//
 };
 
 // Advanced parameters for controlling how Shairport Sync stays active and how it runs a session
index 2ed31deb5791f040832cd984db0afcdc11e6335d..84c3e1f541589b50cdaa17c37d19c85376470639 100644 (file)
@@ -402,9 +402,9 @@ int parse_options(int argc, char **argv) {
 // i.e. when reducing volume, reduce the sw first before reducing the software.
 // this is because some hw mixers mute at the bottom of their range, and they don't always advertise
 // this fact
-  config.resend_wait_before_check = 0.10; // wait this many seconds before requesting the resending of a missing packet
-  config.resend_wait_between_checks = 0.25; // wait this many seconds before again requesting the resending of a missing packet
-  config.resend_last_check_before_use = 0.10; // give up if the packet is still missing this close to when it's needed
+  config.resend_control_first_check_time = 0.10; // wait this many seconds before requesting the resending of a missing packet
+  config.resend_control_check_interval_time = 0.25; // wait this many seconds before again requesting the resending of a missing packet
+  config.resend_control_last_check_time = 0.10; // give up if the packet is still missing this close to when it's needed
 
 #ifdef CONFIG_METADATA_HUB
   config.cover_art_cache_dir = "/tmp/shairport-sync/.cache/coverart";
@@ -766,6 +766,44 @@ int parse_options(int argc, char **argv) {
         } else
           die("Invalid alac_decoder option choice \"%s\". It should be \"hammerton\" or \"apple\"");
       }
+      
+      
+      /* Get the resend control settings. */
+      if (config_lookup_float(config.cfg, "general.resend_control_first_check_time",
+                              &dvalue)) {
+        if ((dvalue >= 0.0) && (dvalue <= 3.0))
+          config.resend_control_first_check_time = dvalue;
+        else
+          warn("Invalid general resend_control_first_check_time setting \"%d\". It should "
+              "be "
+              "between 0.0 and 3.0, "
+              "inclusive. The setting remains at %f seconds.",
+              dvalue, config.resend_control_first_check_time);
+      }
+
+      if (config_lookup_float(config.cfg, "general.resend_control_check_interval_time",
+                              &dvalue)) {
+        if ((dvalue >= 0.0) && (dvalue <= 3.0))
+          config.resend_control_check_interval_time = dvalue;
+        else
+          warn("Invalid general resend_control_check_interval_time setting \"%d\". It should "
+              "be "
+              "between 0.0 and 3.0, "
+              "inclusive. The setting remains at %f seconds.",
+              dvalue, config.resend_control_check_interval_time);
+      }
+
+      if (config_lookup_float(config.cfg, "general.resend_control_last_check_time",
+                              &dvalue)) {
+        if ((dvalue >= 0.0) && (dvalue <= 3.0))
+          config.resend_control_last_check_time = dvalue;
+        else
+          warn("Invalid general resend_control_last_check_time setting \"%d\". It should "
+              "be "
+              "between 0.0 and 3.0, "
+              "inclusive. The setting remains at %f seconds.",
+              dvalue, config.resend_control_last_check_time);
+      }
 
       /* Get the default latency. Deprecated! */
       if (config_lookup_int(config.cfg, "latencies.default", &value))