Add a frames per second output. This should be exact if the machine is connected...

diff --git a/audio.h b/audio.h
index dc7eb873f7dcd984a019c25a7ae47a2209c1d5ed..2a15587ce4f505e7bdeb00b291f51461b8fbc566 100644 (file)
--- a/audio.h
+++ b/audio.h
@@ -33,6 +33,7 @@ typedef struct {
   // will change dynamically, so keep watching it. Implemented in ALSA only.
   // returns a negative error code if there's a problem
   int (*delay)(long *the_delay); // snd_pcm_sframes_t is a signed long
+  int (*rate_info)(uint64_t *elapsed_time, uint64_t *frames_played); // use this to get the true rate of the DAC
 
   // may be NULL, in which case soft volume is applied
   void (*volume)(double vol);

diff --git a/audio_alsa.c b/audio_alsa.c
index 3f00fddd9865a7832f0865f0c6e7c6a932713d3e..556fd9579095e8cb4634ff56cb8362d1ae3d0474 100644 (file)
--- a/audio_alsa.c
+++ b/audio_alsa.c
@@ -35,6 +35,7 @@
 #include <pthread.h>
 #include <stdio.h>
 #include <unistd.h>
+#include <inttypes.h>
 
 static void help(void);
 static int init(int argc, char **argv);
@@ -45,6 +46,7 @@ static void stop(void);
 static void flush(void);
 int delay(long *the_delay);
 void do_mute(int request);
+int get_rate_information(uint64_t *elapsed_time, uint64_t *frames_played);
 
 static void volume(double vol);
 void do_volume(double vol);
@@ -64,6 +66,7 @@ audio_output audio_alsa = {
     .flush = &flush,
     .delay = &delay,
     .play = &play,
+    .rate_info = &get_rate_information,
     .mute = NULL,   // a function will be provided if it can, and is allowed to, do hardware mute
     .volume = NULL, // a function will be provided if it can do hardware volume
     .parameters = &parameters};
@@ -110,6 +113,9 @@ int alsa_characteristics_already_listed = 0;
 static snd_pcm_uframes_t period_size_requested, buffer_size_requested;
 static int set_period_size_request, set_buffer_size_request;
 
+static uint64_t time_of_first_frame;
+static uint64_t frames_sent_for_playing;
+
 static void help(void) {
   printf("    -d output-device    set the output device [default*|...]\n"
          "    -m mixer-device     set the mixer device ['output-device'*|...]\n"
@@ -810,6 +816,9 @@ static void start(int i_sample_rate, int i_sample_format) {
     sample_format = SPS_FORMAT_S16; // default
   else
     sample_format = i_sample_format;
+  
+  time_of_first_frame = 0;
+  frames_sent_for_playing = 0;
 }
 
 int delay(long *the_delay) {
@@ -829,20 +838,23 @@ int delay(long *the_delay) {
               snd_strerror(reply), *the_delay);
         snd_pcm_recover(alsa_handle, reply, 1);
       }
-    } else if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_PREPARED) {
-      *the_delay = 0;
-      reply = 0; // no error
     } else {
-      if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_XRUN) {
+      time_of_first_frame = 0;
+      if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_PREPARED) {
         *the_delay = 0;
         reply = 0; // no error
       } else {
-        reply = -EIO;
-        debug(1, "Error -- ALSA delay(): bad state: %d.", snd_pcm_state(alsa_handle));
-      }
-      if ((derr = snd_pcm_prepare(alsa_handle))) {
-        snd_pcm_recover(alsa_handle, derr, 1);
-        debug(1, "Error preparing after delay error: \"%s\".", snd_strerror(derr));
+        if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_XRUN) {
+          *the_delay = 0;
+          reply = 0; // no error
+        } else {
+          reply = -EIO;
+          debug(1, "Error -- ALSA delay(): bad state: %d.", snd_pcm_state(alsa_handle));
+        }
+        if ((derr = snd_pcm_prepare(alsa_handle))) {
+          snd_pcm_recover(alsa_handle, derr, 1);
+          debug(1, "Error preparing after delay error: \"%s\".", snd_strerror(derr));
+        }
       }
     }
     debug_mutex_unlock(&alsa_mutex, 3);
@@ -853,6 +865,16 @@ int delay(long *the_delay) {
   }
 }
 
+int get_rate_information(uint64_t *elapsed_time, uint64_t *frames_played) {
+  long frames_left = 0;
+  int result = delay(&frames_left);
+  if (result >= 0) {
+    *elapsed_time = get_absolute_time_in_fp()-time_of_first_frame;
+    *frames_played = frames_sent_for_playing - frames_left;
+  }
+  return result;
+}
+
 static void play(void *buf, int samples) {
   // debug(3,"audio_alsa play called.");
   int ret = 0;
@@ -876,6 +898,7 @@ static void play(void *buf, int samples) {
         snd_pcm_recover(alsa_handle, err, 1);
         debug(1, "Error preparing after underrun: \"%s\".", snd_strerror(err));
       }
+      time_of_first_frame = 0;
     }
     if ((snd_pcm_state(alsa_handle) == SND_PCM_STATE_PREPARED) ||
         (snd_pcm_state(alsa_handle) == SND_PCM_STATE_RUNNING)) {
@@ -885,11 +908,16 @@ static void play(void *buf, int samples) {
         debug(1, "empty buffer being passed to pcm_writei -- skipping it");
       if ((samples != 0) && (buf != NULL)) {
         err = alsa_pcm_write(alsa_handle, buf, samples);
+        if (time_of_first_frame == 0) {
+          time_of_first_frame = get_absolute_time_in_fp();
+          frames_sent_for_playing = 0;
+        }       
         if (err < 0) {
           debug(1, "Error %d writing %d samples in play(): \"%s\".", err, samples,
                 snd_strerror(err));
           snd_pcm_recover(alsa_handle, err, 1);
         }
+        frames_sent_for_playing += samples;
       }
     } else {
       debug(1, "Error -- ALSA device in incorrect state (%d) for play.",
@@ -898,6 +926,7 @@ static void play(void *buf, int samples) {
         snd_pcm_recover(alsa_handle, err, 1);
         debug(1, "Error preparing after play error: \"%s\".", snd_strerror(err));
       }
+      time_of_first_frame = 0;
     }
     debug_mutex_unlock(&alsa_mutex, 3);
   }

diff --git a/dbus-service.c b/dbus-service.c
index 5fc78c2569a7c84e2d818df477621f1055123817..90e68a089b730f5e94bafb164ac1a026e18cb015 100644 (file)
--- a/dbus-service.c
+++ b/dbus-service.c
@@ -746,7 +746,6 @@ static void on_dbus_name_acquired(GDBusConnection *connection, const gchar *name
 static void on_dbus_name_lost_again(__attribute__((unused)) GDBusConnection *connection,
                                     __attribute__((unused)) const gchar *name,
                                     __attribute__((unused)) gpointer user_data) {
-  debug(1, "Name lost again.");
   warn("Could not acquire a Shairport Sync native D-Bus interface \"%s\" on the %s bus.", name,
        (config.dbus_service_bus_type == DBT_session) ? "session" : "system");
 }
@@ -754,7 +753,6 @@ static void on_dbus_name_lost_again(__attribute__((unused)) GDBusConnection *con
 static void on_dbus_name_lost(__attribute__((unused)) GDBusConnection *connection,
                               __attribute__((unused)) const gchar *name,
                               __attribute__((unused)) gpointer user_data) {
-  debug(1, "Name lost.");
   // debug(1, "Could not acquire a Shairport Sync native D-Bus interface \"%s\" on the %s bus --
   // will try adding the process "
   //         "number to the end of it.",

diff --git a/player.c b/player.c
index 9bec98937d9988e043a586399c44d8ed9ace775d..1a457334de6dfb45548a9847f0486697e5fb0e13 100644 (file)
--- a/player.c
+++ b/player.c
@@ -1435,8 +1435,12 @@ void player_thread_cleanup_handler(void *arg) {
     int elapsedHours = rawSeconds / 3600;
     int elapsedMin = (rawSeconds / 60) % 60;
     int elapsedSec = rawSeconds % 60;
-    inform("Playback Stopped. Total playing time %02d:%02d:%02d.", elapsedHours, elapsedMin,
-           elapsedSec);
+    if (conn->frame_rate_status == 0)
+      inform("Playback Stopped. Total playing time %02d:%02d:%02d at %0.2f frames per second.", elapsedHours, elapsedMin,
+           elapsedSec,conn->frame_rate);
+    else
+      inform("Playback Stopped. Total playing time %02d:%02d:%02d.", elapsedHours, elapsedMin,
+           elapsedSec);    
   }
 
 #ifdef HAVE_DACP_CLIENT
@@ -1594,6 +1598,9 @@ void *player_thread_func(void *arg) {
   int32_t maximum_buffer_occupancy = INT32_MIN;
 
   conn->playstart = time(NULL);
+  
+  conn->frame_rate = 0.0;
+  conn->frame_rate_status = -1; // zero means okay
 
   conn->buffer_occupancy = 0;
 
@@ -1716,7 +1723,8 @@ void *player_thread_func(void *arg) {
                "resend requests, "
                "min DAC queue size, "
                "min buffer occupancy, "
-               "max buffer occupancy");
+               "max buffer occupancy, "
+               "frames per second");
       } else {
         inform("sync error in milliseconds, "
                "total packets, "
@@ -2289,6 +2297,16 @@ void *player_thread_func(void *arg) {
             if (at_least_one_frame_seen) {
               if ((config.output->delay)) {
                 if (config.no_sync == 0) {
+                  if (config.output->rate_info) {
+                    uint64_t elapsed_play_time, frames_played;
+                    conn->frame_rate_status = config.output->rate_info(&elapsed_play_time,&frames_played);
+                    if (conn->frame_rate_status==0) {
+                      uint64_t elapsed_play_time_microseconds_fp, elapsed_play_time_microseconds;
+                      elapsed_play_time_microseconds_fp = elapsed_play_time * 1000000;
+                      elapsed_play_time_microseconds = elapsed_play_time_microseconds_fp >> 32;
+                      conn->frame_rate = frames_played*1000000.0/elapsed_play_time_microseconds;
+                    }
+                  }
                   inform(
                       "%*.1f," /* Sync error in milliseconds */
                       "%*.1f,"  /* net correction in ppm */
@@ -2300,14 +2318,15 @@ void *player_thread_func(void *arg) {
                       "%*llu,"  /* resend requests */
                       "%*lli,"  /* min DAC queue size */
                       "%*d,"    /* min buffer occupancy */
-                      "%*d",    /* max buffer occupancy */
+                      "%*d,"    /* max buffer occupancy */
+                      "%*.2f",    /* frame rate */
                       10, 1000 * moving_average_sync_error / config.output_rate, 10,
                       moving_average_correction * 1000000 / (352 * conn->output_sample_ratio), 10,
                       moving_average_insertions_plus_deletions * 1000000 /
                           (352 * conn->output_sample_ratio),
                       12, play_number, 7, conn->missing_packets, 7, conn->late_packets, 7,
                       conn->too_late_packets, 7, conn->resend_requests, 7, minimum_dac_queue_size,
-                      5, minimum_buffer_occupancy, 5, maximum_buffer_occupancy);
+                      5, minimum_buffer_occupancy, 5, maximum_buffer_occupancy, 10, conn->frame_rate);
                 } else {
                   inform("%*.1f," /* Sync error in milliseconds */
                          "%*d,"    /* total packets */

diff --git a/player.h b/player.h
index 99dcecb89eece5d8a02b64d759169cb0c88688c9..c92b48898fe5ba1f7570d64436894e7585dec09a 100644 (file)
--- a/player.h
+++ b/player.h
@@ -86,9 +86,15 @@ typedef struct {
   pthread_t thread, timer_requester, rtp_audio_thread, rtp_control_thread, rtp_timing_thread;
   // pthread_t *ptp;
 
+  // buffers to delete on exit
   signed short *tbuf;
   int32_t *sbuf;
   char *outbuf;
+  
+  // for holding the rate information until printed out at the end of a session
+  double frame_rate;
+  int frame_rate_status;
+  
 
   pthread_t *player_thread;
   abuf_t audio_buffer[BUFFER_FRAMES];