From: Mike Brady <4265913+mikebrady@users.noreply.github.com>
Date: Sun, 13 Mar 2022 01:33:53 +0000 (+1100)
Subject: Add buffer size to statistcs information for a Buffered Audio stream.
X-Git-Tag: 4.1-rc1~24^2~252
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=08afa822f536800276183532b7bde48613855e60;p=thirdparty%2Fshairport-sync.git

Add buffer size to statistcs information for a Buffered Audio stream.
---

diff --git a/player.c b/player.c
index 1dd5a0e7..a87198cd 100644
--- a/player.c
+++ b/player.c
@@ -1574,13 +1574,13 @@ int ap1_synced_statistics_print_profile[] =                  {2, 2, 2, 1, 2, 1,
 int ap1_nosync_statistics_print_profile[] =                  {2, 0, 0, 1, 2, 1, 1, 2, 1, 1, 1, 1, 1, 0, 0, 1, 0};
 int ap1_nodelay_statistics_print_profile[] =                 {0, 0, 0, 1, 2, 1, 1, 2, 0, 1, 1, 1, 1, 0, 0, 1, 0};
 
-int ap2_realtime_synced_stream_statistics_print_profile[] =  {2, 2, 2, 1, 2, 1, 1, 2, 1, 1, 1, 0, 1, 2, 2, 0, 0};
-int ap2_realtime_nosync_stream_statistics_print_profile[] =  {2, 0, 0, 1, 2, 1, 1, 2, 1, 1, 1, 0, 1, 0, 0, 0, 0};
-int ap2_realtime_nodelay_stream_statistics_print_profile[] = {0, 0, 0, 1, 2, 1, 1, 2, 0, 1, 1, 0, 1, 0, 0, 0, 0};
+int ap2_realtime_synced_stream_statistics_print_profile[] =  {2, 2, 2, 1, 2, 1, 1, 2, 1, 1, 1, 0, 0, 1, 2, 2, 0, 0};
+int ap2_realtime_nosync_stream_statistics_print_profile[] =  {2, 0, 0, 1, 2, 1, 1, 2, 1, 1, 1, 0, 0, 1, 0, 0, 0, 0};
+int ap2_realtime_nodelay_stream_statistics_print_profile[] = {0, 0, 0, 1, 2, 1, 1, 2, 0, 1, 1, 0, 0, 1, 0, 0, 0, 0};
 
-int ap2_buffered_synced_stream_statistics_print_profile[] =  {2, 2, 2, 1, 0, 0, 0, 0, 1, 1, 1, 0, 0, 2, 2, 0, 0};
-int ap2_buffered_nosync_stream_statistics_print_profile[] =  {2, 0, 0, 1, 0, 0, 0, 0, 1, 1, 1, 0, 0, 0, 0, 0, 0};
-int ap2_buffered_nodelay_stream_statistics_print_profile[] = {0, 0, 0, 1, 0, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0};
+int ap2_buffered_synced_stream_statistics_print_profile[] =  {2, 2, 2, 1, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 2, 2, 0, 0};
+int ap2_buffered_nosync_stream_statistics_print_profile[] =  {2, 0, 0, 1, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 0, 0, 0, 0};
+int ap2_buffered_nodelay_stream_statistics_print_profile[] = {0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0};
 // clang-format on
 
 void statistics_item(const char *heading, const char *format, ...) {
@@ -1900,6 +1900,10 @@ void *player_thread_func(void *arg) {
   int32_t minimum_buffer_occupancy = INT32_MAX;
   int32_t maximum_buffer_occupancy = INT32_MIN;
 
+#ifdef CONFIG_AIRPLAY_2  
+  conn->ap2_audio_buffer_minimum_size = -1;
+#endif
+
   conn->playstart = time(NULL);
 
   conn->raw_frame_rate = 0.0;
@@ -2432,6 +2436,12 @@ void *player_thread_func(void *arg) {
                   statistics_item("min DAC queue", "%*" PRIu64 "", 13, minimum_dac_queue_size);
                   statistics_item("min buffers", "%*" PRIu32 "", 11, minimum_buffer_occupancy);
                   statistics_item("max buffers", "%*" PRIu32 "", 11, maximum_buffer_occupancy);
+#ifdef CONFIG_AIRPLAY_2  
+                  if ( conn->ap2_audio_buffer_minimum_size > 10 * 1024)
+                    statistics_item("min buffer size", "%*" PRIu32 "k", 14, conn->ap2_audio_buffer_minimum_size/1024);
+                  else
+                    statistics_item("min buffer size", "%*" PRIu32 "", 15, conn->ap2_audio_buffer_minimum_size);
+#endif
                   statistics_item("nominal fps", "%*.2f", 11, conn->remote_frame_rate);
                   statistics_item("received fps", "%*.2f", 12, conn->input_frame_rate);
                   if (conn->frame_rate_valid) {
@@ -2466,6 +2476,9 @@ void *player_thread_func(void *arg) {
             minimum_dac_queue_size = UINT64_MAX;  // hack reset
             maximum_buffer_occupancy = INT32_MIN; // can't be less than this
             minimum_buffer_occupancy = INT32_MAX; // can't be more than this
+#ifdef CONFIG_AIRPLAY_2  
+            conn->ap2_audio_buffer_minimum_size = -1;
+#endif
             at_least_one_frame_seen = 0;
           }
 
diff --git a/player.h b/player.h
index 453c5f49..7bc19631 100644
--- a/player.h
+++ b/player.h
@@ -320,6 +320,7 @@ typedef struct {
   uint64_t last_anchor_validity_start_time;
 
   ssize_t ap2_audio_buffer_size;
+  ssize_t ap2_audio_buffer_minimum_size;
   flush_request_t *flush_requests; // if non-null, there are flush requests, mutex protected
   int ap2_flush_requested;
   int ap2_flush_from_valid;
diff --git a/rtp.c b/rtp.c
index 7e38bbec..beefeaea 100644
--- a/rtp.c
+++ b/rtp.c
@@ -1926,12 +1926,18 @@ void *rtp_realtime_audio_receiver(void *arg) {
   pthread_exit(NULL);
 }
 
-ssize_t buffered_read(buffered_tcp_desc *descriptor, void *buf, size_t count) {
+ssize_t buffered_read(buffered_tcp_desc *descriptor, void *buf, size_t count, size_t *bytes_remaining) {
   ssize_t response = -1;
   if (pthread_mutex_lock(&descriptor->mutex) != 0)
     debug(1, "problem with mutex");
   pthread_cleanup_push(mutex_unlock, (void *)&descriptor->mutex);
   if (descriptor->closed == 0) {
+    if ((descriptor->buffer_occupancy == 0) && (descriptor->error_code == 0)) {
+      if (count == 2)
+        debug(2, "buffered_read: waiting for %u bytes (okay at start of a track).", count);
+      else
+        debug(1, "buffered_read: waiting for %u bytes.", count);
+    }    
     while ((descriptor->buffer_occupancy == 0) && (descriptor->error_code == 0)) {
       if (pthread_cond_wait(&descriptor->not_empty_cv, &descriptor->mutex))
         debug(1, "Error waiting for buffered read");
@@ -1940,8 +1946,9 @@ ssize_t buffered_read(buffered_tcp_desc *descriptor, void *buf, size_t count) {
   if (descriptor->buffer_occupancy != 0) {
     ssize_t bytes_to_move = count;
 
-    if (descriptor->buffer_occupancy < count)
+    if (descriptor->buffer_occupancy < count) {
       bytes_to_move = descriptor->buffer_occupancy;
+    }
 
     ssize_t top_gap = descriptor->buffer + descriptor->buffer_max_size - descriptor->toq;
     if (top_gap < bytes_to_move)
@@ -1952,6 +1959,8 @@ ssize_t buffered_read(buffered_tcp_desc *descriptor, void *buf, size_t count) {
     if (descriptor->toq == descriptor->buffer + descriptor->buffer_max_size)
       descriptor->toq = descriptor->buffer;
     descriptor->buffer_occupancy -= bytes_to_move;
+    if (bytes_remaining != NULL)
+      *bytes_remaining = descriptor->buffer_occupancy;
     response = bytes_to_move;
     if (pthread_cond_signal(&descriptor->not_full_cv))
       debug(1, "Error signalling");
@@ -2026,7 +2035,7 @@ void *buffered_tcp_reader(void *arg) {
     if (nread < 0) {
       char errorstring[1024];
       strerror_r(errno, (char *)errorstring, sizeof(errorstring));
-      debug(1, "error in buffered_read %d: \"%s\". Could not recv a packet.", errno, errorstring);
+      debug(1, "error in buffered_tcp_reader %d: \"%s\". Could not recv a packet.", errno, errorstring);
       descriptor->error_code = errno;
     } else if (nread == 0) {
       descriptor->closed = 1;
@@ -2081,13 +2090,13 @@ void av_packet_alloc_cleanup_handler(void *arg) {
 
 // this will read a block of the size specified to the buffer
 // and will return either with the block or on error
-ssize_t lread_sized_block(buffered_tcp_desc *descriptor, void *buf, size_t count) {
+ssize_t lread_sized_block(buffered_tcp_desc *descriptor, void *buf, size_t count, size_t *bytes_remaining) {
   ssize_t response, nread;
   size_t inbuf = 0; // bytes already in the buffer
   int keep_trying = 1;
 
   do {
-    nread = buffered_read(descriptor, buf + inbuf, count - inbuf);
+    nread = buffered_read(descriptor, buf + inbuf, count - inbuf, bytes_remaining);
     if (nread == 0) {
       // a blocking read that returns zero means eof -- implies connection closed
       debug(3, "read_sized_block connection closed.");
@@ -2375,7 +2384,7 @@ void *rtp_buffered_audio_processor(void *arg) {
     int flush_newly_complete = 0;
     int play_newly_stopped = 0;
     // are we in in flush mode, or just about to leave it?
-    debug_mutex_lock(&conn->flush_mutex, 10000, 1); // 10ms is a long time to wait!
+    debug_mutex_lock(&conn->flush_mutex, 25000, 1); // 25 ms is a long time to wait!
     uint32_t flushUntilSeq = conn->ap2_flush_until_sequence_number;
     uint32_t flushUntilTS = conn->ap2_flush_until_rtp_timestamp;
 
@@ -2586,7 +2595,10 @@ void *rtp_buffered_audio_processor(void *arg) {
       // do we will get in a packet of audio
       uint16_t data_len;
       // here we read from the buffer that our thread has been reading
-      nread = lread_sized_block(buffered_audio, &data_len, sizeof(data_len));
+      size_t bytes_remaining_in_buffer;
+      nread = lread_sized_block(buffered_audio, &data_len, sizeof(data_len), &bytes_remaining_in_buffer);
+      if ((conn->ap2_audio_buffer_minimum_size < 0) || (bytes_remaining_in_buffer < (size_t)conn->ap2_audio_buffer_minimum_size))
+        conn->ap2_audio_buffer_minimum_size = bytes_remaining_in_buffer;
       if (nread < 0) {
         char errorstring[1024];
         strerror_r(errno, (char *)errorstring, sizeof(errorstring));
@@ -2597,7 +2609,9 @@ void *rtp_buffered_audio_processor(void *arg) {
       }
       data_len = ntohs(data_len);
       // debug(1,"buffered audio packet of size %u detected.", data_len - 2);
-      nread = lread_sized_block(buffered_audio, packet, data_len - 2);
+      nread = lread_sized_block(buffered_audio, packet, data_len - 2, &bytes_remaining_in_buffer);
+      if ((conn->ap2_audio_buffer_minimum_size < 0) || (bytes_remaining_in_buffer < (size_t)conn->ap2_audio_buffer_minimum_size))
+        conn->ap2_audio_buffer_minimum_size = bytes_remaining_in_buffer;
       // debug(1, "buffered audio packet of size %u received.", nread);
       if (nread < 0) {
         char errorstring[1024];