From: Mike Brady Date: Sat, 28 Jul 2018 18:02:02 +0000 (+0100) Subject: Add a frames per second output. This should be exact if the machine is connected... X-Git-Tag: 3.3RC0~286^2~6 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=c85e7e05d1255624cfc2df0542dc9154cf065610;p=thirdparty%2Fshairport-sync.git Add a frames per second output. This should be exact if the machine is connected up to, say, an NTP time service. It uses CLOCK_MONOTONIC time. --- diff --git a/audio.h b/audio.h index dc7eb873..2a15587c 100644 --- 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 3f00fddd..556fd957 100644 --- a/audio_alsa.c +++ b/audio_alsa.c @@ -35,6 +35,7 @@ #include #include #include +#include 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 = ¶meters}; @@ -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 5fc78c25..90e68a08 100644 --- 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 9bec9893..1a457334 100644 --- 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 99dcecb8..c92b4889 100644 --- 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];