From fd880056fb47c3d426f25b319f2662f3b3e3fbaa Mon Sep 17 00:00:00 2001 From: Mike Brady <4265913+mikebrady@users.noreply.github.com> Date: Mon, 12 Sep 2022 15:19:52 +0100 Subject: [PATCH] Squashed commit of the following: Add three parameters to the backend play() function call -- (1) a flag indicating whether the samples are timed or not. If timed, (2) the timestamp and (3) the local time at which the first frame should be heard. Update missing pipewire library message. Makefile.am fix. Update the SHM version and fix the SHM name so that it works with FreeBSD. Remove redundant (?) AC_HEADER_STDC check. Fix compilation and installation under FreeBSD -- changes to allow building in a separate directory broke the FreeBSD build process. Add AC_CHECK_LIB for gcrypt in case PKG_CHECK_MODULES fails to find it. Find gcrypt using pkg-config Add code to detect when the RTSP channel goes idle for a period, and use it to reset clocks and timings, etc. so that SPS resumes correctly where the source has gone to sleep while playing a realtime stream and has subsequently woken up. Don't exit if a UDP Clock Control packet is empty. Also check minimum packet size. Remove some very experimental code which may cause memory and port leaks. Strip file path from the filename used in debug messages, information messages, warnings and fatal error messages. BB fix to Makefile.am -- overwriting the DBUS stuff with MPRIS definitions, duh. Fix some problems building on FreeBSD and tidy up the use of the "sed" editor. Fix some problems building on picore. Fix an uninitialised variable start using the "nqptp" SMI --- activity_monitor.c | 13 +- audio.h | 15 +- audio_alsa.c | 160 ++--- audio_ao.c | 4 +- audio_dummy.c | 23 +- audio_jack.c | 92 ++- audio_pa.c | 4 +- audio_pipe.c | 4 +- audio_pw.c | 10 +- audio_sndio.c | 112 +--- audio_soundio.c | 4 +- audio_stdout.c | 4 +- common.c | 60 +- common.h | 2 +- configure.ac | 9 +- dacp.c | 3 +- dbus-service.c | 17 +- mdns_avahi.c | 9 +- mdns_external.c | 12 +- mdns_tinysvcmdns.c | 4 +- nqptp-shm-structures.h | 4 +- player.c | 276 +++++--- player.h | 7 +- ptp-utilities.c | 4 +- ptp-utilities.h | 1 + rtp.c | 1420 ++++++++++++++++++++-------------------- rtsp.c | 145 ++-- shairport.c | 26 +- 28 files changed, 1292 insertions(+), 1152 deletions(-) diff --git a/activity_monitor.c b/activity_monitor.c index 4bda32e2..0de7d341 100644 --- a/activity_monitor.c +++ b/activity_monitor.c @@ -56,7 +56,8 @@ pthread_mutex_t activity_monitor_mutex; pthread_cond_t activity_monitor_cv; void going_active(int block) { - // debug(1, "activity_monitor: state transitioning to \"active\" with%s blocking", block ? "" : "out"); + // debug(1, "activity_monitor: state transitioning to \"active\" with%s blocking", block ? "" : + // "out"); if (config.cmd_active_start) command_execute(config.cmd_active_start, "", block); #ifdef CONFIG_METADATA @@ -121,18 +122,16 @@ void activity_monitor_signify_activity(int active) { // So, if the active end procedure is on a timer, it will be executed when the // timeout occurs and the "blocking" status is ignored. - + if ((state == am_inactive) && (player_state == ps_active)) { state = am_active; pthread_mutex_unlock(&activity_monitor_mutex); - going_active( - config.cmd_blocking); + going_active(config.cmd_blocking); } else if ((state == am_active) && (player_state == ps_inactive) && (config.active_state_timeout == 0.0)) { state = am_inactive; pthread_mutex_unlock(&activity_monitor_mutex); - going_inactive( - config.cmd_blocking); + going_inactive(config.cmd_blocking); } else { pthread_mutex_unlock(&activity_monitor_mutex); } @@ -179,7 +178,7 @@ void *activity_monitor_thread_code(void *arg) { // debug(1,"am_state: am_active"); while (player_state != ps_inactive) pthread_cond_wait(&activity_monitor_cv, &activity_monitor_mutex); - + // if it's not already am_inactive, the it should be beginning to time out... if (state != am_inactive) { state = am_timing_out; diff --git a/audio.h b/audio.h index 5ff14195..583b2bbb 100644 --- a/audio.h +++ b/audio.h @@ -4,6 +4,19 @@ #include #include +// clang-format off +// Play samples provided may be from the source, in which case they will be timed +// or they may be generated by Shairport Sync, in which case they will not be timed. + +// Typically these would be samples of silence, which may be dithered, sent during the lead-in to +// the start of the material, or inserted instead of a missing frame, or after a flush. +// clang-format on + +typedef enum { + play_samples_are_untimed = 0, // typically the samples are (possibly dithered) silence + play_samples_are_timed, // timed and numbered. +} play_samples_type; + typedef struct { double current_volume_dB; int32_t minimum_volume_dB; @@ -24,7 +37,7 @@ typedef struct { void (*start)(int sample_rate, int sample_format); // block of samples - int (*play)(void *buf, int samples); + int (*play)(void *buf, int samples, int sample_type, uint32_t timestamp, uint64_t playtime); void (*stop)(void); // may be null if no implemented diff --git a/audio_alsa.c b/audio_alsa.c index 93c25689..fc53ee65 100644 --- a/audio_alsa.c +++ b/audio_alsa.c @@ -52,32 +52,34 @@ typedef struct { int frame_size; } format_record; -static void help(void); -static int init(int argc, char **argv); -static void deinit(void); -static void start(int i_sample_rate, int i_sample_format); -static int play(void *buf, int samples); -static void stop(void); -static void flush(void); -int delay(long *the_delay); -int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, uint64_t *the_delay, - uint64_t *frames_sent_to_dac); - -void *alsa_buffer_monitor_thread_code(void *arg); - -static void volume(double vol); -void do_volume(double vol); -int prepare(void); -int do_play(void *buf, int samples); - -static void parameters(audio_parameters *info); -int mute(int do_mute); // returns true if it actually is allowed to use the mute -static double set_volume; -static int output_method_signalled = 0; // for reporting whether it's using mmap or not +int output_method_signalled = 0; // for reporting whether it's using mmap or not int delay_type_notified = -1; // for controlling the reporting of whether the output device can do // precision delays (e.g. alsa->pulsaudio virtual devices can't) int use_monotonic_clock = 0; // this value will be set when the hardware is initialised +static void help(void); +static int init(int argc, char **argv); +static void deinit(void); +static void start(int i_sample_rate, int i_sample_format); +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime); +static void stop(void); +static void flush(void); +static int delay(long *the_delay); +static int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, + uint64_t *the_delay, uint64_t *frames_sent_to_dac); + +static void *alsa_buffer_monitor_thread_code(void *arg); + +static void volume(double vol); +static void do_volume(double vol); +static int prepare(void); +static int do_play(void *buf, int samples); + +static void parameters(audio_parameters *info); +static int mute(int do_mute); // returns true if it actually is allowed to use the mute +static double set_volume; audio_output audio_alsa = { .name = "alsa", .help = &help, @@ -98,8 +100,8 @@ audio_output audio_alsa = { .volume = NULL, // a function will be provided if it can do hardware volume .parameters = NULL}; // a function will be provided if it can do hardware volume -static pthread_mutex_t alsa_mutex = PTHREAD_MUTEX_INITIALIZER; -static pthread_mutex_t alsa_mixer_mutex = PTHREAD_MUTEX_INITIALIZER; +pthread_mutex_t alsa_mutex = PTHREAD_MUTEX_INITIALIZER; +pthread_mutex_t alsa_mixer_mutex = PTHREAD_MUTEX_INITIALIZER; pthread_t alsa_buffer_monitor_thread; @@ -121,7 +123,7 @@ long stall_monitor_frame_count; // set to delay at start of time, increm uint64_t stall_monitor_error_threshold; // if the time is longer than this, it's // an error -static snd_output_t *output = NULL; +snd_output_t *output = NULL; int frame_size; // in bytes for interleaved stereo int alsa_device_initialised; // boolean to ensure the initialisation is only @@ -133,25 +135,25 @@ yndk_type precision_delay_available_status = snd_pcm_t *alsa_handle = NULL; int alsa_handle_status = ENODEV; // if alsa_handle is NULL, this should say why with a unix error code -static snd_pcm_hw_params_t *alsa_params = NULL; -static snd_pcm_sw_params_t *alsa_swparams = NULL; -static snd_ctl_t *ctl = NULL; -static snd_ctl_elem_id_t *elem_id = NULL; -static snd_mixer_t *alsa_mix_handle = NULL; -static snd_mixer_elem_t *alsa_mix_elem = NULL; -static snd_mixer_selem_id_t *alsa_mix_sid = NULL; -static long alsa_mix_minv, alsa_mix_maxv; -static long alsa_mix_mindb, alsa_mix_maxdb; +snd_pcm_hw_params_t *alsa_params = NULL; +snd_pcm_sw_params_t *alsa_swparams = NULL; +snd_ctl_t *ctl = NULL; +snd_ctl_elem_id_t *elem_id = NULL; +snd_mixer_t *alsa_mix_handle = NULL; +snd_mixer_elem_t *alsa_mix_elem = NULL; +snd_mixer_selem_id_t *alsa_mix_sid = NULL; +long alsa_mix_minv, alsa_mix_maxv; +long alsa_mix_mindb, alsa_mix_maxdb; -static char *alsa_out_dev = "default"; -static char *alsa_mix_dev = NULL; -static char *alsa_mix_ctrl = NULL; -static int alsa_mix_index = 0; -static int has_softvol = 0; +char *alsa_out_dev = "default"; +char *alsa_mix_dev = NULL; +char *alsa_mix_ctrl = NULL; +int alsa_mix_index = 0; +int has_softvol = 0; int64_t dither_random_number_store = 0; -static int volume_set_request = 0; // set when an external request is made to set the volume. +int volume_set_request = 0; // set when an external request is made to set the volume. int mixer_volume_setting_gives_mute = 0; // set when it is discovered that // particular mixer volume setting @@ -164,10 +166,10 @@ int volume_based_mute_is_active = // use this to allow the use of snd_pcm_writei or snd_pcm_mmap_writei snd_pcm_sframes_t (*alsa_pcm_write)(snd_pcm_t *, const void *, snd_pcm_uframes_t) = snd_pcm_writei; -int precision_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, - yndk_type *using_update_timestamps); -int standard_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, - yndk_type *using_update_timestamps); +static int precision_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, + yndk_type *using_update_timestamps); +static int standard_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, + yndk_type *using_update_timestamps); // use this to allow the use of standard or precision delay calculations, with standard the, uh, // standard. @@ -182,7 +184,7 @@ int (*delay_and_status)(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, // If you want it to check again, set precision_delay_available_status to YNDK_DONT_KNOW // first. -int precision_delay_available() { +static int precision_delay_available() { if (precision_delay_available_status == YNDK_DONT_KNOW) { // this is very crude -- if the device is a hardware device, then it's assumed the delay is // precise @@ -247,16 +249,16 @@ int precision_delay_available() { 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; +snd_pcm_uframes_t period_size_requested, buffer_size_requested; +int set_period_size_request, set_buffer_size_request; -static uint64_t frames_sent_for_playing; +uint64_t frames_sent_for_playing; // set to true if there has been a discontinuity between the last reported frames_sent_for_playing // and the present reported frames_sent_for_playing // Note that it will be set when the device is opened, as any previous figures for // frames_sent_for_playing (which Shairport Sync might hold) would be invalid. -static int frames_sent_break_occurred; +int frames_sent_break_occurred; static void help(void) { printf(" -d output-device set the output device, default is \"default\".\n" @@ -270,10 +272,10 @@ static void help(void) { debug(2, "error %d executing a script to list alsa hardware device names", r); } -void set_alsa_out_dev(char *dev) { alsa_out_dev = dev; } +void set_alsa_out_dev(char *dev) { alsa_out_dev = dev; } // ugh -- not static! // assuming pthread cancellation is disabled -int open_mixer() { +static int open_mixer() { int response = 0; if (alsa_mix_ctrl != NULL) { debug(3, "Open Mixer"); @@ -317,7 +319,7 @@ int open_mixer() { } // assuming pthread cancellation is disabled -void close_mixer() { +static void close_mixer() { if (alsa_mix_handle) { snd_mixer_close(alsa_mix_handle); alsa_mix_handle = NULL; @@ -325,7 +327,7 @@ void close_mixer() { } // assuming pthread cancellation is disabled -void do_snd_mixer_selem_set_playback_dB_all(snd_mixer_elem_t *mix_elem, double vol) { +static void do_snd_mixer_selem_set_playback_dB_all(snd_mixer_elem_t *mix_elem, double vol) { if (snd_mixer_selem_set_playback_dB_all(mix_elem, vol, 0) != 0) { debug(1, "Can't set playback volume accurately to %f dB.", vol); if (snd_mixer_selem_set_playback_dB_all(mix_elem, vol, -1) != 0) @@ -386,7 +388,7 @@ sps_format_t auto_format_check_sequence[] = { // assuming pthread cancellation is disabled // if do_auto_setting is true and auto format or auto speed has been requested, // select the settings as appropriate and store them -int actual_open_alsa_device(int do_auto_setup) { +static int actual_open_alsa_device(int do_auto_setup) { // the alsa mutex is already acquired when this is called const snd_pcm_uframes_t minimal_buffer_headroom = 352 * 2; // we accept this much headroom in the hardware buffer, but we'll @@ -867,7 +869,7 @@ int actual_open_alsa_device(int do_auto_setup) { return 0; } -int open_alsa_device(int do_auto_setup) { +static int open_alsa_device(int do_auto_setup) { int result; int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable @@ -876,7 +878,7 @@ int open_alsa_device(int do_auto_setup) { return result; } -int prepare_mixer() { +static int prepare_mixer() { int response = 0; // do any alsa device initialisation (general case) // at present, this is only needed if a hardware mixer is being used @@ -991,7 +993,7 @@ int prepare_mixer() { return response; } -int alsa_device_init() { return prepare_mixer(); } +static int alsa_device_init() { return prepare_mixer(); } static int init(int argc, char **argv) { // for debugging @@ -1383,7 +1385,7 @@ static void deinit(void) { pthread_setcancelstate(oldState, NULL); } -int set_mute_state() { +static int set_mute_state() { int response = 1; // some problem expected, e.g. no mixer or not allowed to use it or disconnected int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable @@ -1436,8 +1438,8 @@ static void start(__attribute__((unused)) int i_sample_rate, } } -int standard_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, - yndk_type *using_update_timestamps) { +static int standard_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, + yndk_type *using_update_timestamps) { int ret = alsa_handle_status; if (using_update_timestamps) *using_update_timestamps = YNDK_NO; @@ -1470,8 +1472,8 @@ int standard_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, return ret; } -int precision_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, - yndk_type *using_update_timestamps) { +static int precision_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, + yndk_type *using_update_timestamps) { snd_pcm_state_t state_temp = SND_PCM_STATE_DISCONNECTED; snd_pcm_sframes_t delay_temp = 0; if (using_update_timestamps) @@ -1635,7 +1637,7 @@ int precision_delay_and_status(snd_pcm_state_t *state, snd_pcm_sframes_t *delay, return ret; } -int delay(long *the_delay) { +static int delay(long *the_delay) { // returns 0 if the device is in a valid state -- SND_PCM_STATE_RUNNING or // SND_PCM_STATE_PREPARED // or SND_PCM_STATE_DRAINING @@ -1667,8 +1669,8 @@ int delay(long *the_delay) { return ret; } -int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, uint64_t *the_delay, - uint64_t *frames_sent_to_dac) { +static int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, + uint64_t *the_delay, uint64_t *frames_sent_to_dac) { // returns 0 if the device is in a valid state -- SND_PCM_STATE_RUNNING or // SND_PCM_STATE_PREPARED // or SND_PCM_STATE_DRAINING. @@ -1709,7 +1711,7 @@ int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, return ret; } /* -int get_rate_information(uint64_t *elapsed_time, uint64_t *frames_played) { +static int get_rate_information(uint64_t *elapsed_time, uint64_t *frames_played) { // elapsed_time is in nanoseconds int response = 0; // zero means okay if (measurement_data_is_valid) { @@ -1724,7 +1726,7 @@ int get_rate_information(uint64_t *elapsed_time, uint64_t *frames_played) { } */ -int do_play(void *buf, int samples) { +static int do_play(void *buf, int samples) { // assuming the alsa_mutex has been acquired // debug(3,"audio_alsa play called."); int oldState; @@ -1809,7 +1811,7 @@ int do_play(void *buf, int samples) { return ret; } -int do_open(int do_auto_setup) { +static int do_open(int do_auto_setup) { int ret = 0; if (alsa_backend_state != abm_disconnected) debug(1, "alsa: do_open() -- opening the output device when it is already " @@ -1838,7 +1840,7 @@ int do_open(int do_auto_setup) { return ret; } -int do_close() { +static int do_close() { debug(2, "alsa: do_close()"); if (alsa_backend_state == abm_disconnected) debug(1, "alsa: do_close() -- closing the output device when it is already " @@ -1863,7 +1865,7 @@ int do_close() { return derr; } -int sub_flush() { +static int sub_flush() { if (alsa_backend_state == abm_disconnected) debug(1, "alsa: do_flush() -- closing the output device when it is already " "disconnected"); @@ -1882,7 +1884,9 @@ int sub_flush() { return derr; } -int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { // play() will change the state of the alsa_backend_mode to abm_playing // also, if the present alsa_backend_state is abm_disconnected, then first the @@ -1919,7 +1923,7 @@ int play(void *buf, int samples) { return ret; } -int prepare(void) { +static int prepare(void) { // this will leave the DAC open / connected. int ret = 0; @@ -1973,8 +1977,8 @@ static void parameters(audio_parameters *info) { info->maximum_volume_dB = alsa_mix_maxdb; } -void do_volume(double vol) { // caller is assumed to have the alsa_mutex when - // using this function +static void do_volume(double vol) { // caller is assumed to have the alsa_mutex when + // using this function debug(3, "Setting volume db to %f.", vol); int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable @@ -2014,7 +2018,7 @@ void do_volume(double vol) { // caller is assumed to have the alsa_mutex when pthread_setcancelstate(oldState, NULL); } -void volume(double vol) { +static void volume(double vol) { volume_set_request = 1; // an external request has been made to set the volume do_volume(vol); } @@ -2038,7 +2042,7 @@ linear_volume; } */ -int mute(int mute_state_requested) { // these would be for external reasons, not +static int mute(int mute_state_requested) { // these would be for external reasons, not // because of the // state of the backend. mute_requested_externally = mute_state_requested; // request a mute for external reasons @@ -2046,13 +2050,13 @@ int mute(int mute_state_requested) { // these would be for extern return set_mute_state(); } /* -void alsa_buffer_monitor_thread_cleanup_function(__attribute__((unused)) void +static void alsa_buffer_monitor_thread_cleanup_function(__attribute__((unused)) void *arg) { debug(1, "alsa: alsa_buffer_monitor_thread_cleanup_function called."); } */ -void *alsa_buffer_monitor_thread_code(__attribute__((unused)) void *arg) { +static void *alsa_buffer_monitor_thread_code(__attribute__((unused)) void *arg) { int frame_count = 0; int error_count = 0; int error_detected = 0; diff --git a/audio_ao.c b/audio_ao.c index 6e203709..64299659 100644 --- a/audio_ao.c +++ b/audio_ao.c @@ -147,7 +147,9 @@ static void start(__attribute__((unused)) int sample_rate, // debug(1,"libao start"); } -static int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { int response = 0; int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable diff --git a/audio_dummy.c b/audio_dummy.c index 70ea755e..4ec1d29d 100644 --- a/audio_dummy.c +++ b/audio_dummy.c @@ -4,7 +4,7 @@ * All rights reserved. * * Modifications for audio synchronisation - * and related work, copyright (c) Mike Brady 2014 + * and related work, copyright (c) Mike Brady 2014 -- 2022 * All rights reserved. * * Permission is hereby granted, free of charge, to any person @@ -30,6 +30,7 @@ #include "audio.h" #include "common.h" +#include // for PRId64 and friends #include #include #include @@ -41,8 +42,26 @@ static void deinit(void) {} static void start(int sample_rate, __attribute__((unused)) int sample_format) { debug(1, "dummy audio output started at %d frames per second.", sample_rate); } +// clang-format off +// Here is a brief explanation of the parameters: +// sample_type is 'play_samples_are_untimed' or 'play_samples_are_timed' defined in audio.h. +// untimed samples are typically silence used by Shairport Sync itself to set up synchronisation or to fill for missing packets of audio -- the timestamp and playtime are zero. +// timed samples come from the client. +// timestamp is the RTP timestamp given to the first frame by the client +// playtime is when the first frame should to be played. It is given in "local time". +// local time is CLOCK_MONOTONIC_RAW if available, or CLOCK_MONOTONIC otherwise, expressed in nanoseconds as an unsigned 64-bit integer (See get_absolute_time_in_ns() in common.c) +// clang-format on + +static int play(__attribute__((unused)) void *buf, __attribute__((unused)) int samples, + int sample_type, uint32_t timestamp, uint64_t playtime) { + + // sample code using some of the extra information + if (sample_type == play_samples_are_timed) { + int64_t lead_time = playtime - get_absolute_time_in_ns(); + debug(1, "leadtime for frame %u is %" PRId64 " nanoseconds, i.e. %f seconds.", timestamp, + lead_time, 0.000000001 * lead_time); + } -static int play(__attribute__((unused)) void *buf, __attribute__((unused)) int samples) { return 0; } diff --git a/audio_jack.c b/audio_jack.c index e87e16a3..4218d245 100644 --- a/audio_jack.c +++ b/audio_jack.c @@ -1,6 +1,6 @@ /* * jack output driver. This file is part of Shairport Sync. - * Copyright (c) 2019 Mike Brady , + * Copyright (c) 2019 -- 2022 Mike Brady <4265913+mikebrady@users.noreply.github.com>, * Jörn Nettingsmeier * * All rights reserved. @@ -40,49 +40,25 @@ typedef jack_default_audio_sample_t sample_t; #define jack_sample_size sizeof(sample_t) // Two-channel, 32bit audio: -static const int bytes_per_frame = NPORTS * jack_sample_size; +const int bytes_per_frame = NPORTS * jack_sample_size; -static pthread_mutex_t buffer_mutex = PTHREAD_MUTEX_INITIALIZER; -static pthread_mutex_t client_mutex = PTHREAD_MUTEX_INITIALIZER; - -int jack_init(int, char **); -void jack_deinit(void); -void jack_start(int, int); -int play(void *, int); -void jack_stop(void); -int jack_delay(long *); -void jack_flush(void); - -audio_output audio_jack = {.name = "jack", - .help = NULL, - .init = &jack_init, - .deinit = &jack_deinit, - .prepare = NULL, - .start = &jack_start, - .stop = NULL, - .is_running = NULL, - .flush = &jack_flush, - .delay = &jack_delay, - .stats = NULL, - .play = &play, - .volume = NULL, - .parameters = NULL, - .mute = NULL}; +pthread_mutex_t buffer_mutex = PTHREAD_MUTEX_INITIALIZER; +pthread_mutex_t client_mutex = PTHREAD_MUTEX_INITIALIZER; // This also affects deinterlacing. // So make it exactly the number of incoming audio channels! -static jack_port_t *port[NPORTS]; -static const char *port_name[NPORTS] = {"out_L", "out_R"}; +jack_port_t *port[NPORTS]; +const char *port_name[NPORTS] = {"out_L", "out_R"}; -static jack_client_t *client; -static jack_nframes_t sample_rate; -static jack_nframes_t jack_latency; +jack_client_t *client; +jack_nframes_t sample_rate; +jack_nframes_t jack_latency; -static jack_ringbuffer_t *jackbuf; -static int flush_please = 0; +jack_ringbuffer_t *jackbuf; +int flush_please = 0; -static jack_latency_range_t latest_latency_range[NPORTS]; -static int64_t time_of_latest_transfer; +jack_latency_range_t latest_latency_range[NPORTS]; +int64_t time_of_latest_transfer; #ifdef CONFIG_SOXR typedef struct soxr_quality { @@ -90,9 +66,9 @@ typedef struct soxr_quality { const char *name; } soxr_quality_t; -static soxr_quality_t soxr_quality_table[] = {{SOXR_VHQ, "very high"}, {SOXR_HQ, "high"}, - {SOXR_MQ, "medium"}, {SOXR_LQ, "low"}, - {SOXR_QQ, "quick"}, {-1, NULL}}; +soxr_quality_t soxr_quality_table[] = {{SOXR_VHQ, "very high"}, {SOXR_HQ, "high"}, + {SOXR_MQ, "medium"}, {SOXR_LQ, "low"}, + {SOXR_QQ, "quick"}, {-1, NULL}}; static int parse_soxr_quality_name(const char *name) { for (soxr_quality_t *s = soxr_quality_table; s->name != NULL; ++s) { @@ -103,9 +79,9 @@ static int parse_soxr_quality_name(const char *name) { return -1; } -static soxr_t soxr = NULL; -static soxr_quality_spec_t quality_spec; -static soxr_io_spec_t io_spec; +soxr_t soxr = NULL; +soxr_quality_spec_t quality_spec; +soxr_io_spec_t io_spec; #endif static inline sample_t sample_conv(short sample) { @@ -204,7 +180,7 @@ static void error(const char *desc) { warn("JACK error: \"%s\"", desc); } // This is the function JACK will call in case of a non-critical event in the library. static void info(const char *desc) { inform("JACK information: \"%s\"", desc); } -int jack_init(__attribute__((unused)) int argc, __attribute__((unused)) char **argv) { +static int jack_init(__attribute__((unused)) int argc, __attribute__((unused)) char **argv) { int i; int bufsz = -1; config.audio_backend_latency_offset = 0; @@ -332,7 +308,7 @@ int jack_init(__attribute__((unused)) int argc, __attribute__((unused)) char **a return 0; } -void jack_deinit() { +static void jack_deinit() { pthread_mutex_lock(&client_mutex); if (jack_deactivate(client)) warn("Error deactivating jack client"); @@ -348,7 +324,7 @@ void jack_deinit() { #endif } -void jack_start(int i_sample_rate, __attribute__((unused)) int i_sample_format) { +static void jack_start(int i_sample_rate, __attribute__((unused)) int i_sample_format) { // Nothing to do, JACK client has already been set up at jack_init(). // Also, we have no say over the sample rate or sample format of JACK, // We convert the 16bit samples to float, and die if the sample rate is != 44k1 without soxr. @@ -367,13 +343,13 @@ void jack_start(int i_sample_rate, __attribute__((unused)) int i_sample_format) #endif } -void jack_flush() { +static void jack_flush() { debug(2, "Only the consumer can safely flush a lock-free ringbuffer. Asking the" " process callback to do it..."); flush_please = 1; } -int jack_delay(long *the_delay) { +static int jack_delay(long *the_delay) { // Semantics change: we now look at the last transfer into the lock-free // ringbuffer, not into the jack buffers directly (because locking those would // violate real-time constraints). On average, that should lead to just a @@ -399,7 +375,9 @@ int jack_delay(long *the_delay) { return 0; } -int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { jack_ringbuffer_data_t v[2] = {0}; size_t i, j, c; jack_nframes_t thisbuf; @@ -445,3 +423,19 @@ int play(void *buf, int samples) { } return 0; } + +audio_output audio_jack = {.name = "jack", + .help = NULL, + .init = &jack_init, + .deinit = &jack_deinit, + .prepare = NULL, + .start = &jack_start, + .stop = NULL, + .is_running = NULL, + .flush = &jack_flush, + .delay = &jack_delay, + .stats = NULL, + .play = &play, + .volume = NULL, + .parameters = NULL, + .mute = NULL}; diff --git a/audio_pa.c b/audio_pa.c index 9d37bc60..c91b76f6 100644 --- a/audio_pa.c +++ b/audio_pa.c @@ -223,7 +223,9 @@ static void start(__attribute__((unused)) int sample_rate, pa_threaded_mainloop_unlock(mainloop); } -static int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { // debug(1,"pa_play of %d samples.",samples); // copy the samples into the queue size_t bytes_to_transfer = samples * 2 * 2; diff --git a/audio_pipe.c b/audio_pipe.c index fcece96b..83b9666f 100644 --- a/audio_pipe.c +++ b/audio_pipe.c @@ -66,7 +66,9 @@ static void start(__attribute__((unused)) int sample_rate, } } -static int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { // if the file is not open, try to open it. char errorstring[1024]; if (fd == -1) { diff --git a/audio_pw.c b/audio_pw.c index 016df41d..4271ba09 100644 --- a/audio_pw.c +++ b/audio_pw.c @@ -1,6 +1,6 @@ /* * Asynchronous Pipewire Backend. This file is part of Shairport Sync. - * Copyright (c) Shairport Sync 2021 + * Copyright (c) Shairport Sync 2021--2022 * All rights reserved. * * Permission is hereby granted, free of charge, to any person @@ -452,8 +452,10 @@ static void flush() { pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL); } -static int play(void *buf, int samples) { - struct pw_buffer *pw_buffer; +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { + struct pw_buffer *pw_buffer = NULL; struct spa_buffer *spa_buffer; struct spa_data *spa_data; int ret; @@ -522,4 +524,4 @@ audio_output audio_pw = {.name = "pw", .play = &play, .volume = NULL, .parameters = NULL, - .mute = NULL}; + .mute = NULL}; \ No newline at end of file diff --git a/audio_sndio.c b/audio_sndio.c index 998290e2..a369bfb5 100644 --- a/audio_sndio.c +++ b/audio_sndio.c @@ -28,42 +28,12 @@ #include #include -static void help(void); -static int init(int, char **); -static void onmove_cb(void *, int); -static void deinit(void); -static void start(int, int); -static int play(void *, int); -static void stop(void); -static void onmove_cb(void *, int); -static int delay(long *); -static void flush(void); -int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, uint64_t *the_delay, - uint64_t *frames_sent_to_dac); - -audio_output audio_sndio = {.name = "sndio", - .help = &help, - .init = &init, - .deinit = &deinit, - .prepare = NULL, - .start = &start, - .stop = &stop, - .is_running = NULL, - .flush = &flush, - .delay = &delay, - .stats = NULL, - .play = &play, - .volume = NULL, - .parameters = NULL, - .mute = NULL}; - static pthread_mutex_t sndio_mutex = PTHREAD_MUTEX_INITIALIZER; static struct sio_hdl *hdl; static int framesize; static size_t played; static size_t written; uint64_t time_of_last_onmove_cb; -uint64_t corrected_time_of_last_onmove_cb; int at_least_one_onmove_cb_seen; struct sio_par par; @@ -90,18 +60,12 @@ static struct sndio_formats formats[] = {{"S8", SPS_FORMAT_S8, 44100, 8, 1, 1, S static void help() { printf(" -d output-device set the output device [default*|...]\n"); } -uint64_t get_uptime_in_ns() { - uint64_t time_now_ns; - struct timespec tn; - clock_gettime(CLOCK_UPTIME_PRECISE, &tn); - uint64_t tnnsec = tn.tv_sec; - tnnsec = tnnsec * 1000000000; - uint64_t tnjnsec = tn.tv_nsec; - time_now_ns = tnnsec + tnjnsec; - return time_now_ns; +void onmove_cb(__attribute__((unused)) void *arg, int delta) { + time_of_last_onmove_cb = get_absolute_time_in_ns(); + at_least_one_onmove_cb_seen = 1; + played += delta; } - static int init(int argc, char **argv) { int found, opt, round, rate, bufsz; unsigned int i; @@ -136,7 +100,7 @@ static int init(int argc, char **argv) { devname = SIO_DEVANY; if (config_lookup_int(config.cfg, "sndio.rate", &rate)) { if (rate % 44100 == 0 && rate >= 44100 && rate <= 352800) { - par.rate = rate; + par.rate = rate; } else { die("sndio: output rate must be a multiple of 44100 and 44100 <= rate <= " "352800"); @@ -188,15 +152,15 @@ static int init(int argc, char **argv) { pthread_cleanup_debug_mutex_lock(&sndio_mutex, 1000, 1); // pthread_mutex_lock(&sndio_mutex); debug(1, "sndio: output device name is \"%s\".", devname); - debug(1, "sndio: rate: %u.",par.rate); - debug(1, "sndio: bits: %u.",par.bits); + debug(1, "sndio: rate: %u.", par.rate); + debug(1, "sndio: bits: %u.", par.bits); hdl = sio_open(devname, SIO_PLAY, 0); if (!hdl) die("sndio: cannot open audio device"); written = played = 0; - time_of_last_onmove_cb = 0; + time_of_last_onmove_cb = 0; at_least_one_onmove_cb_seen = 0; for (i = 0; i < sizeof(formats) / sizeof(formats[0]); i++) { @@ -265,7 +229,9 @@ static void start(__attribute__((unused)) int sample_rate, pthread_cleanup_pop(1); // unlock the mutex } -static int play(void *buf, int frames) { +static int play(void *buf, int frames, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { if (frames > 0) { // pthread_mutex_lock(&sndio_mutex); pthread_cleanup_debug_mutex_lock(&sndio_mutex, 1000, 1); @@ -285,20 +251,13 @@ static void stop() { pthread_cleanup_pop(1); // unlock the mutex } -static void onmove_cb(__attribute__((unused)) void *arg, int delta) { - time_of_last_onmove_cb = get_uptime_in_ns(); // this is not (?) adjusted ("disciplined") by NTP - corrected_time_of_last_onmove_cb = get_monotonic_time_in_ns(); // this is ("disciplined") by NTP - at_least_one_onmove_cb_seen = 1; - played += delta; -} - int get_delay(long *delay) { int response = 0; size_t estimated_extra_frames_output = 0; if (at_least_one_onmove_cb_seen) { // when output starts, the onmove_cb callback will be made // calculate the difference in time between now and when the last callback occurred, // and use it to estimate the frames that would have been output - uint64_t time_difference = get_uptime_in_ns() - time_of_last_onmove_cb; + uint64_t time_difference = get_absolute_time_in_ns() - time_of_last_onmove_cb; uint64_t frame_difference = (time_difference * par.rate) / 1000000000; estimated_extra_frames_output = frame_difference; // sanity check -- total estimate can not exceed frames written. @@ -332,35 +291,18 @@ static void flush() { pthread_cleanup_pop(1); // unlock the mutex } -/* -// this doesn't seem to be very accurate, so not using it. -int stats(uint64_t *raw_measurement_time, uint64_t *corrected_measurement_time, uint64_t *the_delay, - uint64_t *frames_sent_to_dac) { - // returns 0 if the device is in a valid state - // returns the actual delay if running or 0 if prepared in *the_delay - // returns the present estimated value of frames played - // otherwise return a non-zero value - int ret = 0; - *the_delay = 0; - - int oldState; - pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable - long my_delay = 0; // initialised to stop a compiler warning - pthread_cleanup_debug_mutex_lock(&sndio_mutex, 1000, 1); - *raw_measurement_time = time_of_last_onmove_cb; - *corrected_measurement_time = corrected_time_of_last_onmove_cb; // this is ("disciplined") by NTP - get_delay(&my_delay); - ret = frames_sent_break_occurred; // will be zero unless an error like an underrun occurred - frames_sent_break_occurred = 0; // reset it. - if (frames_sent_to_dac != NULL) - *frames_sent_to_dac = frames_sent_for_playing; - pthread_cleanup_pop(1); // unlock the mutex - pthread_setcancelstate(oldState, NULL); - uint64_t hd = my_delay; // note: snd_pcm_sframes_t is a long - *the_delay = hd; - if (at_least_one_onmove_cb_seen == 0) - ret = 1; - return ret; -} -*/ - +audio_output audio_sndio = {.name = "sndio", + .help = &help, + .init = &init, + .deinit = &deinit, + .prepare = NULL, + .start = &start, + .stop = &stop, + .is_running = NULL, + .flush = &flush, + .delay = &delay, + .stats = NULL, + .play = &play, + .volume = NULL, + .parameters = NULL, + .mute = NULL}; diff --git a/audio_soundio.c b/audio_soundio.c index ccf44bf7..83347b5b 100644 --- a/audio_soundio.c +++ b/audio_soundio.c @@ -164,7 +164,9 @@ static void start(int sample_rate, int sample_format) { debug(1, "libsoundio output started\n"); } -static int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { // int err; int free_bytes = soundio_ring_buffer_free_count(ring_buffer); int written_bytes = 0; diff --git a/audio_stdout.c b/audio_stdout.c index 61fdc744..61d91bfa 100644 --- a/audio_stdout.c +++ b/audio_stdout.c @@ -43,7 +43,9 @@ static void start(__attribute__((unused)) int sample_rate, fd = STDOUT_FILENO; } -static int play(void *buf, int samples) { +static int play(void *buf, int samples, __attribute__((unused)) int sample_type, + __attribute__((unused)) uint32_t timestamp, + __attribute__((unused)) uint64_t playtime) { char errorstring[1024]; int warned = 0; int rc = write(fd, buf, samples * 4); diff --git a/common.c b/common.c index e522a681..dbbbef60 100644 --- a/common.c +++ b/common.c @@ -62,12 +62,12 @@ #endif #ifdef COMPILE_FOR_OSX -#include -#include -#include #include #include #include +#include +#include +#include #endif #ifdef CONFIG_OPENSSL @@ -455,9 +455,10 @@ char *generate_preliminary_string(char *buffer, size_t buffer_length, double tss return insertion_point; } -void _die(const char *filename, const int linenumber, const char *format, ...) { +void _die(const char *thefilename, const int linenumber, const char *format, ...) { int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); + char b[16384]; b[0] = 0; char *s; @@ -468,9 +469,12 @@ void _die(const char *filename, const int linenumber, const char *format, ...) { uint64_t time_since_last_debug_message = time_now - ns_time_at_last_debug_message; ns_time_at_last_debug_message = time_now; pthread_mutex_unlock(&debug_timing_lock); + char *basec = strdup(thefilename); + char *filename = basename(basec); s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000, 1.0 * time_since_last_debug_message / 1000000000, filename, linenumber, " *fatal error: "); + free(basec); } else { strncpy(b, "fatal error: ", sizeof(b)); s = b + strlen(b); @@ -485,7 +489,7 @@ void _die(const char *filename, const int linenumber, const char *format, ...) { exit(EXIT_FAILURE); } -void _warn(const char *filename, const int linenumber, const char *format, ...) { +void _warn(const char *thefilename, const int linenumber, const char *format, ...) { int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); char b[16384]; @@ -498,9 +502,12 @@ void _warn(const char *filename, const int linenumber, const char *format, ...) uint64_t time_since_last_debug_message = time_now - ns_time_at_last_debug_message; ns_time_at_last_debug_message = time_now; pthread_mutex_unlock(&debug_timing_lock); + char *basec = strdup(thefilename); + char *filename = basename(basec); s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000, 1.0 * time_since_last_debug_message / 1000000000, filename, linenumber, " *warning: "); + free(basec); } else { strncpy(b, "warning: ", sizeof(b)); s = b + strlen(b); @@ -513,11 +520,12 @@ void _warn(const char *filename, const int linenumber, const char *format, ...) pthread_setcancelstate(oldState, NULL); } -void _debug(const char *filename, const int linenumber, int level, const char *format, ...) { +void _debug(const char *thefilename, const int linenumber, int level, const char *format, ...) { if (level > debuglev) return; int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); + char b[16384]; b[0] = 0; pthread_mutex_lock(&debug_timing_lock); @@ -526,9 +534,12 @@ void _debug(const char *filename, const int linenumber, int level, const char *f uint64_t time_since_last_debug_message = time_now - ns_time_at_last_debug_message; ns_time_at_last_debug_message = time_now; pthread_mutex_unlock(&debug_timing_lock); + char *basec = strdup(thefilename); + char *filename = basename(basec); char *s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000, 1.0 * time_since_last_debug_message / 1000000000, filename, linenumber, " "); + free(basec); va_list args; va_start(args, format); vsnprintf(s, sizeof(b) - (s - b), format, args); @@ -537,7 +548,7 @@ void _debug(const char *filename, const int linenumber, int level, const char *f pthread_setcancelstate(oldState, NULL); } -void _inform(const char *filename, const int linenumber, const char *format, ...) { +void _inform(const char *thefilename, const int linenumber, const char *format, ...) { int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); char b[16384]; @@ -550,9 +561,12 @@ void _inform(const char *filename, const int linenumber, const char *format, ... uint64_t time_since_last_debug_message = time_now - ns_time_at_last_debug_message; ns_time_at_last_debug_message = time_now; pthread_mutex_unlock(&debug_timing_lock); + char *basec = strdup(thefilename); + char *filename = basename(basec); s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000, 1.0 * time_since_last_debug_message / 1000000000, filename, linenumber, " "); + free(basec); } else { s = b; } @@ -1242,11 +1256,11 @@ uint64_t get_monotonic_time_in_ns() { if (sTimebaseInfo.denom == 0) die("could not initialise Mac timebase info in get_monotonic_time_in_ns()."); - // Do the maths. We hope that the multiplication doesn't - // overflow; the price you pay for working in fixed point. + // Do the maths. We hope that the multiplication doesn't + // overflow; the price you pay for working in fixed point. - // this gives us nanoseconds - time_now_ns = time_now_mach * sTimebaseInfo.numer / sTimebaseInfo.denom; + // this gives us nanoseconds + time_now_ns = time_now_mach * sTimebaseInfo.numer / sTimebaseInfo.denom; #endif return time_now_ns; @@ -1306,8 +1320,8 @@ uint64_t get_absolute_time_in_ns() { if (sTimebaseInfo.denom == 0) die("could not initialise Mac timebase info in get_absolute_time_in_ns()."); - // this gives us nanoseconds - time_now_ns = time_now_mach * sTimebaseInfo.numer / sTimebaseInfo.denom; + // this gives us nanoseconds + time_now_ns = time_now_mach * sTimebaseInfo.numer / sTimebaseInfo.denom; #endif return time_now_ns; @@ -1520,21 +1534,20 @@ int _debug_mutex_lock(pthread_mutex_t *mutex, useconds_t dally_time, const char return pthread_mutex_lock(mutex); int oldState; pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); - if (debuglevel != 0) + if (debuglevel != 0) _debug(filename, line, 3, "mutex_lock \"%s\".", mutexname); // only if you really ask for it! int result = sps_pthread_mutex_timedlock(mutex, dally_time); if (result == ETIMEDOUT) { - _debug(filename, line, debuglevel, - "mutex_lock \"%s\" failed to lock after %f ms -- now waiting unconditionally to lock it.", - mutexname, dally_time * 1E-3); + _debug( + filename, line, debuglevel, + "mutex_lock \"%s\" failed to lock after %f ms -- now waiting unconditionally to lock it.", + mutexname, dally_time * 1E-3); result = pthread_mutex_lock(mutex); if (result == 0) - _debug(filename, line, debuglevel, - " ...mutex_lock \"%s\" locked successfully.", - mutexname); + _debug(filename, line, debuglevel, " ...mutex_lock \"%s\" locked successfully.", mutexname); else - _debug(filename, line, debuglevel, - " ...mutex_lock \"%s\" exited with error code: %u", mutexname, result); + _debug(filename, line, debuglevel, " ...mutex_lock \"%s\" exited with error code: %u", + mutexname, result); } pthread_setcancelstate(oldState, NULL); return result; @@ -1954,7 +1967,7 @@ int get_device_id(uint8_t *id, int int_length) { } else { t = id; int found = 0; - + for (ifa = ifaddr; ((ifa != NULL) && (found == 0)); ifa = ifa->ifa_next) { #ifdef AF_PACKET if ((ifa->ifa_addr) && (ifa->ifa_addr->sa_family == AF_PACKET)) { @@ -1980,7 +1993,6 @@ int get_device_id(uint8_t *id, int int_length) { } #endif #endif - } freeifaddrs(ifaddr); } diff --git a/common.h b/common.h index ffacb9f1..0d5ae2e7 100644 --- a/common.h +++ b/common.h @@ -37,7 +37,7 @@ typedef enum { typedef enum { TOE_normal, TOE_emergency, - TOE_dbus // a dbus request was made -- don't wait for the dbus thread to exit + TOE_dbus // a dbus request was made -- don't wait for the dbus thread to exit } type_of_exit_type; #define sps_extra_code_output_stalled 32768 diff --git a/configure.ac b/configure.ac index ac965045..b0f53cd9 100644 --- a/configure.ac +++ b/configure.ac @@ -75,21 +75,18 @@ fi AC_ARG_WITH([dummy],[AS_HELP_STRING([--with-dummy],[include the dummy audio back end])]) if test "x$with_dummy" = "xyes" ; then - AC_MSG_RESULT(include the dummy audio back end) AC_DEFINE([CONFIG_DUMMY], 1, [Include a fake audio backend.]) fi AM_CONDITIONAL([USE_DUMMY], [test "x$with_dummy" = "xyes" ]) AC_ARG_WITH([stdout],[AS_HELP_STRING([--with-stdout],[include the stdout audio back end])]) if test "x$with_stdout" = "xyes" ; then - AC_MSG_RESULT(include the stdout audio back end) AC_DEFINE([CONFIG_STDOUT], 1, [Include an audio backend to output to standard output (stdout).]) fi AM_CONDITIONAL([USE_STDOUT], [test "x$with_stdout" = "xyes"]) AC_ARG_WITH([pipe],[AS_HELP_STRING([--with-pipe],[include the pipe audio back end])]) if test "x$with_pipe" = "xyes" ; then - AC_MSG_RESULT(include the pipe audio back end) AC_DEFINE([CONFIG_PIPE], 1, [Include an audio backend to output to a unix pipe.]) fi AM_CONDITIONAL([USE_PIPE], [test "x$with_pipe" = "xyes" ]) @@ -320,9 +317,9 @@ if test "x$with_pw" = "xyes" ; then PKG_CHECK_MODULES( [PIPEWIRE], [libpipewire-0.3 >= 0.3.24], [CFLAGS="${PIPEWIRE_CFLAGS} ${CFLAGS} -Wno-missing-field-initializers" LIBS="${PIPEWIRE_LIBS} ${LIBS}"], - [AC_MSG_ERROR(Pipewire support requires the libpipewire-dev library!)]) + [AC_MSG_ERROR(Pipewire support requires the libpipewire library -- libpipewire-0.3-dev suggested!)]) else - AC_CHECK_LIB([pipewire], [pw_stream_queue_buffer], , AC_MSG_ERROR(Pipewire support requires the libpipewire-dev library.)) + AC_CHECK_LIB([pipewire], [pw_stream_queue_buffer], , AC_MSG_ERROR(Pipewire support requires the libpipewire library -- libpipewire-0.3-dev suggested!)) fi fi AM_CONDITIONAL([USE_PW], [test "x$with_pw" = "xyes"]) @@ -409,7 +406,6 @@ AM_CONDITIONAL([USE_METADATA], [test "x$with_metadata" = "xyes"]) AC_ARG_WITH(airplay-2, [AS_HELP_STRING([--with-airplay-2],[Build for AirPlay 2])]) if test "x$with_airplay_2" = "xyes" ; then AC_DEFINE([CONFIG_AIRPLAY_2], 1, [Build for AirPlay 2]) - AC_MSG_RESULT(>>Include libraries required for AirPlay 2) PKG_CHECK_MODULES([libplist], [libplist >= 2.0.0],[CFLAGS="${libplist_CFLAGS} ${CFLAGS}" LIBS="${libplist_LIBS} ${LIBS}"],[ PKG_CHECK_MODULES([libplist], [libplist-2.0 >= 2.0.0],[CFLAGS="${libplist_CFLAGS} ${CFLAGS}" LIBS="${libplist_LIBS} ${LIBS}"],[ AC_MSG_ERROR(AirPlay 2 support requires libplist 2.0.0 or later -- search for pkg libplist-dev on Debian or libplist-2.2.0 or later on FreeBSD!) @@ -456,7 +452,6 @@ fi AM_CONDITIONAL([HAVE_XMLTOMAN], [test -n "$XMLTOMAN"]) # Checks for header files. -AC_HEADER_STDC AC_CHECK_HEADERS([getopt_long.h]) AC_CHECK_HEADERS([arpa/inet.h fcntl.h limits.h mach/mach.h memory.h netdb.h netinet/in.h stdint.h stdlib.h string.h sys/ioctl.h sys/socket.h sys/time.h syslog.h unistd.h]) diff --git a/dacp.c b/dacp.c index 1355fdc6..73164ae2 100644 --- a/dacp.c +++ b/dacp.c @@ -206,7 +206,8 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) { pthread_cleanup_push(addrinfo_cleanup, (void *)&res); // only do this one at a time -- not sure it is necessary, but better safe than sorry - // int mutex_reply = sps_pthread_mutex_timedlock(&dacp_conversation_lock, 2000000, command, 1); + // int mutex_reply = sps_pthread_mutex_timedlock(&dacp_conversation_lock, 2000000, command, + // 1); int mutex_reply = debug_mutex_lock(&dacp_conversation_lock, 2000000, 1); // int mutex_reply = pthread_mutex_lock(&dacp_conversation_lock); if (mutex_reply == 0) { diff --git a/dbus-service.c b/dbus-service.c index c68aac9b..c461e12a 100644 --- a/dbus-service.c +++ b/dbus-service.c @@ -572,17 +572,17 @@ gboolean notify_drift_tolerance_callback(ShairportSync *skeleton, } gboolean notify_volume_callback(ShairportSync *skeleton, - __attribute__((unused)) gpointer user_data) { + __attribute__((unused)) gpointer user_data) { gdouble iv = shairport_sync_get_volume(skeleton); if (((iv >= -30.0) && (iv <= 0.0)) || (iv == -144.0)) { debug(2, ">> setting volume to %7.4f.", iv); - + lock_player(); config.airplay_volume = iv; if (playing_conn != NULL) player_volume(iv, playing_conn); unlock_player(); - + } else { debug(1, ">> invalid volume: %f. Ignored.", iv); shairport_sync_set_volume(skeleton, config.airplay_volume); @@ -805,8 +805,7 @@ static gboolean on_handle_remote_command(ShairportSync *skeleton, GDBusMethodInv return TRUE; } -static gboolean on_handle_drop_session(ShairportSync *skeleton, - GDBusMethodInvocation *invocation, +static gboolean on_handle_drop_session(ShairportSync *skeleton, GDBusMethodInvocation *invocation, __attribute__((unused)) gpointer user_data) { if (playing_conn != NULL) debug(1, ">> stopping current play session"); @@ -862,16 +861,16 @@ static void on_dbus_name_acquired(GDBusConnection *connection, const gchar *name G_CALLBACK(notify_loudness_threshold_callback), NULL); g_signal_connect(shairportSyncSkeleton, "notify::drift-tolerance", G_CALLBACK(notify_drift_tolerance_callback), NULL); - g_signal_connect(shairportSyncSkeleton, "notify::volume", - G_CALLBACK(notify_volume_callback), NULL); + g_signal_connect(shairportSyncSkeleton, "notify::volume", G_CALLBACK(notify_volume_callback), + NULL); g_signal_connect(shairportSyncSkeleton, "handle-quit", G_CALLBACK(on_handle_quit), NULL); g_signal_connect(shairportSyncSkeleton, "handle-remote-command", G_CALLBACK(on_handle_remote_command), NULL); - g_signal_connect(shairportSyncSkeleton, "handle-drop-session", - G_CALLBACK(on_handle_drop_session), NULL); + g_signal_connect(shairportSyncSkeleton, "handle-drop-session", G_CALLBACK(on_handle_drop_session), + NULL); g_signal_connect(shairportSyncDiagnosticsSkeleton, "notify::verbosity", G_CALLBACK(notify_verbosity_callback), NULL); diff --git a/mdns_avahi.c b/mdns_avahi.c index 6f66181d..c154ec60 100644 --- a/mdns_avahi.c +++ b/mdns_avahi.c @@ -47,11 +47,10 @@ #include #include - void threaded_poll_unlock(void *arg) { avahi_threaded_poll_unlock((AvahiThreadedPoll *)arg); } -#define pthread_avahi_threaded_poll_lock_and_push(mu) \ - avahi_threaded_poll_lock(mu); \ +#define pthread_avahi_threaded_poll_lock_and_push(mu) \ + avahi_threaded_poll_lock(mu); \ pthread_cleanup_push(threaded_poll_unlock, (void *)mu) #define check_avahi_response(debugLevelArg, veryUnLikelyArgumentName) \ @@ -347,8 +346,8 @@ static int avahi_update(char **txt_records, char **secondary_txt_records) { else selected_interface = AVAHI_IF_UNSPEC; pthread_avahi_threaded_poll_lock_and_push(tpoll); - //avahi_threaded_poll_lock(tpoll); - //pthread_cleanup_push(threaded_poll_unlock, (void *)tpoll) + // avahi_threaded_poll_lock(tpoll); + // pthread_cleanup_push(threaded_poll_unlock, (void *)tpoll) if (txt_records != NULL) { if (text_record_string_list) diff --git a/mdns_external.c b/mdns_external.c index cf4d215a..9d4bff1c 100644 --- a/mdns_external.c +++ b/mdns_external.c @@ -81,9 +81,9 @@ static int fork_execvp(const char *file, char *const argv[]) { } static int mdns_external_avahi_register(char *ap1name, __attribute__((unused)) char *ap2name, - __attribute__((unused)) int port, - __attribute__((unused)) char **txt_records, - __attribute__((unused)) char **secondary_txt_records) { + __attribute__((unused)) int port, + __attribute__((unused)) char **txt_records, + __attribute__((unused)) char **secondary_txt_records) { char mdns_port[6]; snprintf(mdns_port, sizeof(mdns_port), "%d", config.port); @@ -123,9 +123,9 @@ static int mdns_external_avahi_register(char *ap1name, __attribute__((unused)) c } static int mdns_external_dns_sd_register(char *ap1name, __attribute__((unused)) char *ap2name, - __attribute__((unused)) int port, - __attribute__((unused)) char **txt_records, - __attribute__((unused)) char **secondary_txt_records) { + __attribute__((unused)) int port, + __attribute__((unused)) char **txt_records, + __attribute__((unused)) char **secondary_txt_records) { char mdns_port[6]; snprintf(mdns_port, sizeof(mdns_port), "%d", config.port); diff --git a/mdns_tinysvcmdns.c b/mdns_tinysvcmdns.c index 516160da..b11de208 100644 --- a/mdns_tinysvcmdns.c +++ b/mdns_tinysvcmdns.c @@ -39,8 +39,8 @@ static struct mdnsd *svr = NULL; static int mdns_tinysvcmdns_register(char *ap1name, __attribute__((unused)) char *ap2name, int port, - __attribute__((unused)) char **txt_records, - __attribute__((unused)) char **secondary_txt_records) { + __attribute__((unused)) char **txt_records, + __attribute__((unused)) char **secondary_txt_records) { struct ifaddrs *ifalist; struct ifaddrs *ifa; diff --git a/nqptp-shm-structures.h b/nqptp-shm-structures.h index f3861b44..3dbe0c90 100644 --- a/nqptp-shm-structures.h +++ b/nqptp-shm-structures.h @@ -20,7 +20,9 @@ #ifndef NQPTP_SHM_STRUCTURES_H #define NQPTP_SHM_STRUCTURES_H -#define NQPTP_SHM_STRUCTURES_VERSION 7 +#define NQPTP_INTERFACE_NAME "/nqptp" + +#define NQPTP_SHM_STRUCTURES_VERSION 8 #define NQPTP_CONTROL_PORT 9000 // The control port expects a UDP packet with the first space-delimited string diff --git a/player.c b/player.c index e8d5dc1e..68a3b5bf 100644 --- a/player.c +++ b/player.c @@ -4,7 +4,7 @@ * All rights reserved. * * Modifications for audio synchronisation, AirPlay 2 - * and related work, copyright (c) Mike Brady 2014 -- 2021 + * and related work, copyright (c) Mike Brady 2014 -- 2022 * All rights reserved. * * Permission is hereby granted, free of charge, to any person @@ -119,7 +119,7 @@ int32_t modulo_32_offset(uint32_t from, uint32_t to) { return to - from; } void do_flush(uint32_t timestamp, rtsp_conn_info *conn); -static void ab_resync(rtsp_conn_info *conn) { +void ab_resync(rtsp_conn_info *conn) { int i; for (i = 0; i < BUFFER_FRAMES; i++) { conn->audio_buffer[i].ready = 0; @@ -326,7 +326,7 @@ static int init_alac_decoder(int32_t fmtp[12], rtsp_conn_info *conn) { // We are going to go on that basis - // clang-format on + // clang-format on alac_file *alac; @@ -408,7 +408,7 @@ void get_audio_buffer_size_and_occupancy(unsigned int *size, unsigned int *occup void player_put_packet(int original_format, seq_t seqno, uint32_t actual_timestamp, uint8_t *data, int len, rtsp_conn_info *conn) { - + // if it's original format, it has a valid seqno and must be decoded // otherwise, it can take the next seqno and doesn't need decoding. @@ -897,6 +897,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { conn->flush_rtp_timestamp = 0; debug_mutex_unlock(&conn->flush_mutex, 0); } + debug_mutex_lock(&conn->flush_mutex, 1000, 0); pthread_cleanup_push(mutex_unlock, &conn->flush_mutex); if (conn->flush_requested == 1) { @@ -921,40 +922,92 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { abuf_t *firstPacket = conn->audio_buffer + BUFIDX(conn->ab_read); abuf_t *lastPacket = conn->audio_buffer + BUFIDX(conn->ab_write - 1); if ((firstPacket != NULL) && (firstPacket->ready)) { - // discard flushes more than 10 seconds into the future -- they are probably bogus uint32_t first_frame_in_buffer = firstPacket->given_timestamp; - int32_t offset_from_first_frame = - (int32_t)(conn->flush_rtp_timestamp - first_frame_in_buffer); - if (offset_from_first_frame > (int)conn->input_rate * 10) { - debug( - 1, - "flush request: sanity check -- flush frame %u is too far into the future from " - "the first frame %u -- discarded.", - conn->flush_rtp_timestamp, first_frame_in_buffer); - drop_request = 1; - } else { - if ((lastPacket != NULL) && (lastPacket->ready)) { - // we have enough information to check if the flush is needed or can be discarded - uint32_t last_frame_in_buffer = - lastPacket->given_timestamp + lastPacket->length - 1; - // now we have to work out if the flush frame is in the buffer - // if it is later than the end of the buffer, flush everything and keep the - // request active. if it is in the buffer, we need to flush part of the buffer. - // Actually we flush the entire buffer and drop the request. if it is before the - // buffer, no flush is needed. Drop the request. - if (offset_from_first_frame > 0) { - int32_t offset_to_last_frame = - (int32_t)(last_frame_in_buffer - conn->flush_rtp_timestamp); - if (offset_to_last_frame >= 0) { + int32_t offset_from_first_frame = conn->flush_rtp_timestamp - first_frame_in_buffer; + if ((lastPacket != NULL) && (lastPacket->ready)) { + // we have enough information to check if the flush is needed or can be discarded + uint32_t last_frame_in_buffer = + lastPacket->given_timestamp + lastPacket->length - 1; + + // clang-format off + // Now we have to work out if the flush frame is in the buffer. + + // If it is later than the end of the buffer, flush everything and keep the + // request active. + + // If it is in the buffer, we need to flush part of the buffer. + // (Actually we flush the entire buffer and drop the request.) + + // If it is before the buffer, no flush is needed. Drop the request. + // clang-format on + + if (offset_from_first_frame > 0) { + int32_t offset_to_last_frame = last_frame_in_buffer - conn->flush_rtp_timestamp; + if (offset_to_last_frame >= 0) { + debug(2, + "flush request: flush frame %u active -- buffer contains %u frames, from " + "%u to %u.", + conn->flush_rtp_timestamp, + last_frame_in_buffer - first_frame_in_buffer + 1, first_frame_in_buffer, + last_frame_in_buffer); + + // We need to drop all complete frames leading up to the frame containing + // the flush request frame. + int32_t offset_to_flush_frame = 0; + abuf_t *current_packet = NULL; + do { + current_packet = conn->audio_buffer + BUFIDX(conn->ab_read); + if (current_packet != NULL) { + uint32_t last_frame_in_current_packet = + current_packet->given_timestamp + current_packet->length - 1; + offset_to_flush_frame = + conn->flush_rtp_timestamp - last_frame_in_current_packet; + if (offset_to_flush_frame > 0) { + debug(2, + "flush to %u request: flush buffer %u, from " + "%u to %u. ab_write is: %u.", + conn->flush_rtp_timestamp, conn->ab_read, + current_packet->given_timestamp, + current_packet->given_timestamp + current_packet->length - 1, + conn->ab_write); + conn->ab_read++; + } + } else { + debug(1, "NULL current_packet"); + } + } while ((current_packet == NULL) || (offset_to_flush_frame > 0)); + // now remove any frames from the buffer that are before the flush frame itself. + int32_t frames_to_remove = + conn->flush_rtp_timestamp - current_packet->given_timestamp; + if (frames_to_remove > 0) { + debug(2, "%u frames to remove from current buffer", frames_to_remove); + void *dest = (void *)current_packet->data; + void *source = dest + conn->input_bytes_per_frame * frames_to_remove; + size_t frames_remaining = (current_packet->length - frames_to_remove); + memmove(dest, source, frames_remaining * conn->input_bytes_per_frame); + current_packet->given_timestamp = conn->flush_rtp_timestamp; + current_packet->length = frames_remaining; + } + debug( + 2, + "flush request: flush frame %u complete -- buffer contains %u frames, from " + "%u to %u -- flushed to %u in buffer %u, with %u frames remaining.", + conn->flush_rtp_timestamp, last_frame_in_buffer - first_frame_in_buffer + 1, + first_frame_in_buffer, last_frame_in_buffer, + current_packet->given_timestamp, conn->ab_read, + last_frame_in_buffer - current_packet->given_timestamp + 1); + drop_request = 1; + } else { + if (conn->flush_rtp_timestamp == last_frame_in_buffer + 1) { debug( 2, - "flush request: flush frame %u active -- buffer contains %u frames, from " + "flush request: flush frame %u completed -- buffer contained %u frames, " + "from " "%u to %u", conn->flush_rtp_timestamp, last_frame_in_buffer - first_frame_in_buffer + 1, first_frame_in_buffer, last_frame_in_buffer); drop_request = 1; - flush_needed = 1; } else { debug(2, "flush request: flush frame %u pending -- buffer contains %u frames, " @@ -963,18 +1016,17 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { conn->flush_rtp_timestamp, last_frame_in_buffer - first_frame_in_buffer + 1, first_frame_in_buffer, last_frame_in_buffer); - flush_needed = 1; } - } else { - debug(2, - "flush request: flush frame %u expired -- buffer contains %u frames, " - "from %u " - "to %u", - conn->flush_rtp_timestamp, - last_frame_in_buffer - first_frame_in_buffer + 1, first_frame_in_buffer, - last_frame_in_buffer); - drop_request = 1; + flush_needed = 1; } + } else { + debug(2, + "flush request: flush frame %u expired -- buffer contains %u frames, " + "from %u " + "to %u", + conn->flush_rtp_timestamp, last_frame_in_buffer - first_frame_in_buffer + 1, + first_frame_in_buffer, last_frame_in_buffer); + drop_request = 1; } } } @@ -999,14 +1051,56 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { dac_delay = 0; } if (drop_request) { - debug(2, "flush request: request dropped."); conn->flush_requested = 0; conn->flush_rtp_timestamp = 0; conn->flush_output_flushed = 0; } pthread_cleanup_pop(1); // unlock the conn->flush_mutex + + // skip out-of-date frames, and even more if we haven't seen the first frame + int out_of_date = 1; + uint32_t should_be_frame; + + uint64_t time_to_aim_for = local_time_now; + uint64_t desired_lead_time = 120000000; + if (conn->first_packet_timestamp == 0) + time_to_aim_for = time_to_aim_for + desired_lead_time; + + while ((conn->ab_synced) && ((conn->ab_write - conn->ab_read) > 0) && (out_of_date != 0)) { + abuf_t *thePacket = conn->audio_buffer + BUFIDX(conn->ab_read); + if ((thePacket != NULL) && (thePacket->ready)) { + local_time_to_frame(time_to_aim_for, &should_be_frame, conn); + // debug(1,"should_be frame is %u.",should_be_frame); + int32_t frame_difference = thePacket->given_timestamp - should_be_frame; + if (frame_difference < 0) { + debug(2, "Dropping out of date packet %u with timestamp %u. Lead time is %f seconds.", + conn->ab_read, thePacket->given_timestamp, + frame_difference * 1.0 / 44100.0 + desired_lead_time * 0.000000001); + conn->ab_read++; + } else { + if (conn->first_packet_timestamp == 0) + debug(2, "Accepting packet %u with timestamp %u. Lead time is %f seconds.", + conn->ab_read, thePacket->given_timestamp, + frame_difference * 1.0 / 44100.0 + desired_lead_time * 0.000000001); + out_of_date = 0; + } + } else { + debug(2, "Packet %u empty or not ready.", conn->ab_read); + conn->ab_read++; + } + } + if (conn->ab_synced) { curframe = conn->audio_buffer + BUFIDX(conn->ab_read); + if (curframe != NULL) { + uint64_t should_be_time; + frame_to_local_time(curframe->given_timestamp, &should_be_time, conn); + int64_t time_difference = should_be_time - local_time_now; + debug(3, "Check packet from buffer %u, timestamp %u, %f seconds ahead.", conn->ab_read, + curframe->given_timestamp, 0.000000001 * time_difference); + } else { + debug(3, "Check packet from buffer %u, empty.", conn->ab_read); + } if ((conn->ab_read != conn->ab_write) && (curframe->ready)) { // it could be synced and empty, under @@ -1034,13 +1128,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { conn->first_packet_timestamp = curframe->given_timestamp; // we will keep buffering until we are // supposed to start playing this -#ifdef CONFIG_METADATA - // say we have started receiving frames here - debug(2, "pffr"); - send_ssnc_metadata( - 'pffr', NULL, 0, - 0); // "first frame received", but don't wait if the queue is locked -#endif + // Here, calculate when we should start playing. We need to know when to allow the // packets to be sent to the player. @@ -1064,24 +1152,16 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { int64_t lt = conn->first_packet_time_to_play - local_time_now; - if (lt < 100000000) { - debug(2, - "Connection %d: Short lead time for first frame %" PRId64 - ": %f seconds. Flushing 0.5 seconds", - conn->connection_number, conn->first_packet_timestamp, lt * 0.000000001); - do_flush(conn->first_packet_timestamp + 5 * 4410, conn); - } else { - debug(2, "Connection %d: Lead time for first frame %" PRId64 ": %f seconds.", - conn->connection_number, conn->first_packet_timestamp, lt * 0.000000001); - } - /* - int64_t lateness = local_time_now - conn->first_packet_time_to_play; - if (lateness > 0) { - debug(1, "First packet is %" PRId64 " nanoseconds late! Flushing 0.5 - seconds", lateness); - - } - */ + // can't be too late because we skipped late packets already, FLW. + debug(2, "Connection %d: Lead time for first frame %" PRId64 ": %f seconds.", + conn->connection_number, conn->first_packet_timestamp, lt * 0.000000001); +#ifdef CONFIG_METADATA + // say we have started receiving frames here + debug(2, "pffr"); + send_ssnc_metadata( + 'pffr', NULL, 0, + 0); // "first frame received", but don't wait if the queue is locked +#endif } if (conn->first_packet_time_to_play != 0) { @@ -1168,7 +1248,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { conn->previous_random_number = generate_zero_frames( silence, fs, config.output_format, conn->enable_dither, conn->previous_random_number); - config.output->play(silence, fs); + config.output->play(silence, fs, play_samples_are_untimed, 0, 0); debug(3, "Sent %" PRId64 " frames of silence", fs); free(silence); have_sent_prefiller_silence = 1; @@ -1213,7 +1293,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { conn->previous_random_number = generate_zero_frames(silence, fs, config.output_format, conn->enable_dither, conn->previous_random_number); - config.output->play(silence, fs); + config.output->play(silence, fs, play_samples_are_untimed, 0, 0); free(silence); } frame_gap -= fs; @@ -1299,7 +1379,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { // reset_input_flow_metrics(conn); // don't do a full flush parameters reset conn->initial_reference_time = 0; conn->initial_reference_timestamp = 0; - conn->first_packet_timestamp = 0; // make sure the first packet isn't late + conn->first_packet_timestamp = 0; // make sure the first packet isn't late } do_wait = 1; } @@ -1311,9 +1391,9 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { if (conn->input_rate == 0) die("input_rate is zero -- should never happen!"); uint64_t time_to_wait_for_wakeup_ns = - 1000000000 / conn->input_rate; // this is time period of one frame + 1000000000 / conn->input_rate; // this is time period of one frame time_to_wait_for_wakeup_ns *= 12 * 352; // two full 352-frame packets - time_to_wait_for_wakeup_ns /= 3; // two thirds of a packet time + time_to_wait_for_wakeup_ns /= 3; // two thirds of a packet time #ifdef COMPILE_FOR_LINUX_AND_FREEBSD_AND_CYGWIN_AND_OPENBSD uint64_t time_of_wakeup_ns = get_realtime_in_ns() + time_to_wait_for_wakeup_ns; @@ -1580,7 +1660,7 @@ int ap2_realtime_synced_stream_statistics_print_profile[] = {2, 2, 2, 0, 2, 1, int ap2_realtime_nosync_stream_statistics_print_profile[] = {2, 0, 0, 0, 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, 0, 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, 0, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 2, 2, 0, 0}; +int ap2_buffered_synced_stream_statistics_print_profile[] = {2, 2, 2, 0, 0, 0, 0, 0, 1, 1, 0, 1, 0, 0, 2, 2, 0, 0}; int ap2_buffered_nosync_stream_statistics_print_profile[] = {2, 0, 0, 0, 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, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0}; // clang-format on @@ -1644,8 +1724,8 @@ void player_thread_cleanup_handler(void *arg) { ":%02" PRId64 ". " "Output: %0.2f (raw), %0.2f (corrected) " "frames per second.", - conn->connection_number, elapsedHours, elapsedMin, elapsedSec, - conn->raw_frame_rate, conn->corrected_frame_rate); + conn->connection_number, elapsedHours, elapsedMin, elapsedSec, conn->raw_frame_rate, + conn->corrected_frame_rate); else inform("Connection %d: Playback Stopped. Total playing time %02" PRId64 ":%02" PRId64 ":%02" PRId64 ".", @@ -1746,8 +1826,10 @@ void *player_thread_func(void *arg) { rtsp_conn_info *conn = (rtsp_conn_info *)arg; uint64_t previous_frames_played = 0; // initialised to avoid a "possibly uninitialised" warning - uint64_t previous_raw_measurement_time = 0; // initialised to avoid a "possibly uninitialised" warning - uint64_t previous_corrected_measurement_time = 0; // initialised to avoid a "possibly uninitialised" warning + uint64_t previous_raw_measurement_time = + 0; // initialised to avoid a "possibly uninitialised" warning + uint64_t previous_corrected_measurement_time = + 0; // initialised to avoid a "possibly uninitialised" warning int previous_frames_played_valid = 0; // pthread_cleanup_push(player_thread_initial_cleanup_handler, arg); @@ -2146,7 +2228,8 @@ void *player_thread_func(void *arg) { conn->previous_random_number = generate_zero_frames( silence, conn->max_frames_per_packet * conn->output_sample_ratio, config.output_format, conn->enable_dither, conn->previous_random_number); - config.output->play(silence, conn->max_frames_per_packet * conn->output_sample_ratio); + config.output->play(silence, conn->max_frames_per_packet * conn->output_sample_ratio, + play_samples_are_untimed, 0, 0); free(silence); } } else if (conn->play_number_after_flush < 10) { @@ -2168,7 +2251,8 @@ void *player_thread_func(void *arg) { conn->previous_random_number = generate_zero_frames( silence, conn->max_frames_per_packet * conn->output_sample_ratio, config.output_format, conn->enable_dither, conn->previous_random_number); - config.output->play(silence, conn->max_frames_per_packet * conn->output_sample_ratio); + config.output->play(silence, conn->max_frames_per_packet * conn->output_sample_ratio, + play_samples_are_untimed, 0, 0); free(silence); } } else { @@ -2458,7 +2542,8 @@ void *player_thread_func(void *arg) { #endif statistics_item("Nominal FPS", "%*.2f", 11, conn->remote_frame_rate); statistics_item("Received FPS", "%*.2f", 12, conn->input_frame_rate); - // only make the next two columns appear if we are getting stats information from the back end + // only make the next two columns appear if we are getting stats information from + // the back end if (config.output->stats) { if (conn->frame_rate_valid) { statistics_item("Output FPS (r)", "%*.2f", 14, conn->raw_frame_rate); @@ -2543,7 +2628,8 @@ void *player_thread_func(void *arg) { conn->connection_number); } } else { - if (resp != -EBUSY) // delay errors can be reported if the device is (hopefully temporarily) busy + if (resp != -EBUSY) // delay errors can be reported if the device is (hopefully + // temporarily) busy debug(1, "Delay error %d when checking running latency.", resp); } } @@ -2572,10 +2658,11 @@ void *player_thread_func(void *arg) { // interpreted as a signed number, should yield the difference _and_ the ordering. sync_error = should_be_frame - will_be_frame; // this is done in int64_t form - + // int64_t t_ping = should_be_frame - conn->anchor_rtptime; // if (t_ping < 0) - // debug(1, "Frame %" PRIu64 " is %" PRId64 " frames before anchor time %" PRIu64 ".", should_be_frame, -t_ping, conn->anchor_rtptime); + // debug(1, "Frame %" PRIu64 " is %" PRId64 " frames before anchor time %" PRIu64 ".", + // should_be_frame, -t_ping, conn->anchor_rtptime); // sign-extend the r-bit unsigned int calculation by treating it as an r-bit signed // integer @@ -2628,7 +2715,8 @@ void *player_thread_func(void *arg) { "final sync adjustment: %" PRId64 " silent frames added with a bias of %" PRId64 " frames.", -sync_error, first_frame_early_bias); - config.output->play(final_adjustment_silence, final_adjustment_length_sized); + config.output->play(final_adjustment_silence, final_adjustment_length_sized, + play_samples_are_untimed, 0, 0); free(final_adjustment_silence); } else { warn("Failed to allocate memory for a final_adjustment_silence buffer of %d " @@ -2690,11 +2778,12 @@ void *player_thread_func(void *arg) { (int64_t)(config.resyncthreshold * config.output_rate); // number of samples if ((sync_error > 0) && (sync_error > filler_length)) { debug(1, - "Large positive sync error of %" PRId64 + "Large positive (i.e. late) sync error of %" PRId64 " frames (%f seconds), at frame: %" PRIu32 ".", sync_error, (sync_error * 1.0) / config.output_rate, inframe->given_timestamp); - //debug(1, "%" PRId64 " frames sent to DAC. DAC buffer contains %" PRId64 " frames.", + // debug(1, "%" PRId64 " frames sent to DAC. DAC buffer contains %" PRId64 " + // frames.", // frames_sent_for_play, actual_delay); // the sync error is output frames, but we have to work out how many source frames // to drop there may be a multiple (the conn->output_sample_ratio) of output frames @@ -2714,11 +2803,11 @@ void *player_thread_func(void *arg) { } else if ((sync_error < 0) && ((-sync_error) > filler_length)) { debug(1, - "Large negative sync error of %" PRId64 + "Large negative (i.e. early) sync error of %" PRId64 " frames (%f seconds), at frame: %" PRIu32 ".", sync_error, (sync_error * 1.0) / config.output_rate, inframe->given_timestamp); - debug(1, "%" PRId64 " frames sent to DAC. DAC buffer contains %" PRId64 " frames.", + debug(3, "%" PRId64 " frames sent to DAC. DAC buffer contains %" PRId64 " frames.", frames_sent_for_play, actual_delay); int64_t silence_length = -sync_error; if (silence_length > (filler_length * 5)) @@ -2732,7 +2821,8 @@ void *player_thread_func(void *arg) { conn->enable_dither, conn->previous_random_number); debug(2, "Play a silence of %d frames.", silence_length_sized); - config.output->play(long_silence, silence_length_sized); + config.output->play(long_silence, silence_length_sized, play_samples_are_untimed, + 0, 0); free(long_silence); } else { warn("Failed to allocate memory for a long_silence buffer of %d frames for a " @@ -2917,7 +3007,10 @@ void *player_thread_func(void *arg) { generate_zero_frames(conn->outbuf, play_samples, config.output_format, conn->enable_dither, conn->previous_random_number); } - config.output->play(conn->outbuf, play_samples); + uint64_t should_be_time; + frame_to_local_time(inframe->given_timestamp, &should_be_time, conn); + config.output->play(conn->outbuf, play_samples, play_samples_are_timed, + inframe->given_timestamp, should_be_time); } } @@ -2962,7 +3055,10 @@ void *player_thread_func(void *arg) { generate_zero_frames(conn->outbuf, play_samples, config.output_format, conn->enable_dither, conn->previous_random_number); } - config.output->play(conn->outbuf, play_samples); // remove the (short*)! + uint64_t should_be_time; + frame_to_local_time(inframe->given_timestamp, &should_be_time, conn); + config.output->play(conn->outbuf, play_samples, play_samples_are_timed, + inframe->given_timestamp, should_be_time); } } diff --git a/player.h b/player.h index 54d648dd..1c18567a 100644 --- a/player.h +++ b/player.h @@ -128,7 +128,6 @@ typedef struct { int is_encrypted; } pair_cipher_bundle; // cipher context and buffers - typedef struct { struct pair_setup_context *setup_ctx; struct pair_verify_context *verify_ctx; @@ -151,6 +150,7 @@ typedef struct flush_request_t { typedef struct { int connection_number; // for debug ID purposes, nothing else... int resend_interval; // this is really just for debugging + int rtsp_link_is_idle; // if true, this indicates if the client asleep char *UserAgent; // free this on teardown int AirPlayVersion; // zero if not an AirPlay session. Used to help calculate latency int latency_warning_issued; @@ -287,6 +287,9 @@ typedef struct { // this is what connects an rtp timestamp to the remote time + int udp_clock_is_initialised; + int udp_clock_sender_is_initialised; + int anchor_remote_info_is_valid; // these can be modified if the master clock changes over time @@ -426,6 +429,8 @@ void get_audio_buffer_size_and_occupancy(unsigned int *size, unsigned int *occup int32_t modulo_32_offset(uint32_t from, uint32_t to); +void ab_resync(rtsp_conn_info *conn); + int player_prepare_to_play(rtsp_conn_info *conn); int player_play(rtsp_conn_info *conn); int player_stop(rtsp_conn_info *conn); diff --git a/ptp-utilities.c b/ptp-utilities.c index c7d88aa7..559b62ea 100644 --- a/ptp-utilities.c +++ b/ptp-utilities.c @@ -39,12 +39,10 @@ #endif #define __STDC_FORMAT_MACROS #include "common.h" +#include "ptp-utilities.h" #include #include -#include "nqptp-shm-structures.h" -#include "ptp-utilities.h" - int shm_fd; void *mapped_addr = NULL; diff --git a/ptp-utilities.h b/ptp-utilities.h index 86d2b499..761a5cae 100644 --- a/ptp-utilities.h +++ b/ptp-utilities.h @@ -27,6 +27,7 @@ #define __PTP_UTILITIES_H #include "config.h" +#include "nqptp-shm-structures.h" #include int ptp_get_clock_info(uint64_t *actual_clock_id, uint64_t *time_of_sample, uint64_t *raw_offset, diff --git a/rtp.c b/rtp.c index d215b8a4..ce1376c4 100644 --- a/rtp.c +++ b/rtp.c @@ -333,228 +333,242 @@ void *rtp_control_receiver(void *arg) { ssize_t nread; while (1) { nread = recv(conn->control_socket, packet, sizeof(packet), 0); + if (conn->rtsp_link_is_idle == 0) { + if (nread >= 0) { + if ((config.diagnostic_drop_packet_fraction == 0.0) || + (drand48() > config.diagnostic_drop_packet_fraction)) { - if (nread >= 0) { + ssize_t plen = nread; + if (packet[1] == 0xd4) { // sync data + // clang-format off + /* + // the following stanza is for debugging only -- normally commented out. + { + char obf[4096]; + char *obfp = obf; + int obfc; + for (obfc = 0; obfc < plen; obfc++) { + snprintf(obfp, 3, "%02X", packet[obfc]); + obfp += 2; + }; + *obfp = 0; - if ((config.diagnostic_drop_packet_fraction == 0.0) || - (drand48() > config.diagnostic_drop_packet_fraction)) { - ssize_t plen = nread; - if (packet[1] == 0xd4) { // sync data - /* - // the following stanza is for debugging only -- normally commented out. - { - char obf[4096]; - char *obfp = obf; - int obfc; - for (obfc = 0; obfc < plen; obfc++) { - snprintf(obfp, 3, "%02X", packet[obfc]); - obfp += 2; - }; - *obfp = 0; - - - // get raw timestamp information - // I think that a good way to understand these timestamps is that - // (1) the rtlt below is the timestamp of the frame that should be playing at the - // client-time specified in the packet if there was no delay - // and (2) that the rt below is the timestamp of the frame that should be playing - // at the client-time specified in the packet on this device taking account of - // the delay - // Thus, (3) the latency can be calculated by subtracting the second from the - // first. - // There must be more to it -- there something missing. - - // In addition, it seems that if the value of the short represented by the second - // pair of bytes in the packet is 7 - // then an extra time lag is expected to be added, presumably by - // the AirPort Express. - - // Best guess is that this delay is 11,025 frames. - - uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency - uint32_t rt = nctohl(&packet[16]); // raw timestamp - - uint32_t fl = nctohs(&packet[2]); // - - debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and %u, - giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt); - //debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 " - respectively.",monotonic_timestamp(rt, conn),monotonic_timestamp(rtlt, conn)); - } - */ - if (conn->local_to_remote_time_difference) { // need a time packet to be interchanged - // first... - uint64_t ps, pn; + // get raw timestamp information + // I think that a good way to understand these timestamps is that + // (1) the rtlt below is the timestamp of the frame that should be playing at the + // client-time specified in the packet if there was no delay + // and (2) that the rt below is the timestamp of the frame that should be playing + // at the client-time specified in the packet on this device taking account of + // the delay + // Thus, (3) the latency can be calculated by subtracting the second from the + // first. + // There must be more to it -- there something missing. - ps = nctohl(&packet[8]); - ps = ps * 1000000000; // this many nanoseconds from the whole seconds - pn = nctohl(&packet[12]); - pn = pn * 1000000000; - pn = pn >> 32; // this many nanoseconds from the fractional part - remote_time_of_sync = ps + pn; + // In addition, it seems that if the value of the short represented by the second + // pair of bytes in the packet is 7 + // then an extra time lag is expected to be added, presumably by + // the AirPort Express. - // debug(1,"Remote Sync Time: " PRIu64 "",remote_time_of_sync); + // Best guess is that this delay is 11,025 frames. - sync_rtp_timestamp = nctohl(&packet[16]); - uint32_t rtp_timestamp_less_latency = nctohl(&packet[4]); + uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency + uint32_t rt = nctohl(&packet[16]); // raw timestamp - // debug(1,"Sync timestamp is %u.",ntohl(*((uint32_t *)&packet[16]))); + uint32_t fl = nctohs(&packet[2]); // - if (config.userSuppliedLatency) { - if (config.userSuppliedLatency != conn->latency) { - debug(1, "Using the user-supplied latency: %" PRIu32 ".", - config.userSuppliedLatency); - } - conn->latency = config.userSuppliedLatency; - } else { + debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and %u, + giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt); + //debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 " + respectively.",monotonic_timestamp(rt, conn),monotonic_timestamp(rtlt, conn)); + } + */ + // clang-format off + if (conn->local_to_remote_time_difference) { // need a time packet to be interchanged + // first... + uint64_t ps, pn; - // It seems that the second pair of bytes in the packet indicate whether a fixed - // delay of 11,025 frames should be added -- iTunes set this field to 7 and - // AirPlay sets it to 4. + ps = nctohl(&packet[8]); + ps = ps * 1000000000; // this many nanoseconds from the whole seconds + pn = nctohl(&packet[12]); + pn = pn * 1000000000; + pn = pn >> 32; // this many nanoseconds from the fractional part + remote_time_of_sync = ps + pn; - // However, on older versions of AirPlay, the 11,025 frames seem to be necessary too + // debug(1,"Remote Sync Time: " PRIu64 "",remote_time_of_sync); - // The value of 11,025 (0.25 seconds) is a guess based on the "Audio-Latency" - // parameter - // returned by an AE. + sync_rtp_timestamp = nctohl(&packet[16]); + uint32_t rtp_timestamp_less_latency = nctohl(&packet[4]); - // Sigh, it would be nice to have a published protocol... + // debug(1,"Sync timestamp is %u.",ntohl(*((uint32_t *)&packet[16]))); - uint16_t flags = nctohs(&packet[2]); - uint32_t la = sync_rtp_timestamp - rtp_timestamp_less_latency; // note, this might - // loop around in - // modulo. Not sure if - // you'll get an error! - // debug(1, "Latency from the sync packet is %" PRIu32 " frames.", la); - - if ((flags == 7) || ((conn->AirPlayVersion > 0) && (conn->AirPlayVersion <= 353)) || - ((conn->AirPlayVersion > 0) && (conn->AirPlayVersion >= 371))) { - la += config.fixedLatencyOffset; - // debug(1, "Latency offset by %" PRIu32" frames due to the source flags and version - // giving a latency of %" PRIu32 " frames.", config.fixedLatencyOffset, la); - } - if ((conn->maximum_latency) && (conn->maximum_latency < la)) - la = conn->maximum_latency; - if ((conn->minimum_latency) && (conn->minimum_latency > la)) - la = conn->minimum_latency; - - const uint32_t max_frames = ((3 * BUFFER_FRAMES * 352) / 4) - 11025; - - if (la > max_frames) { - warn("An out-of-range latency request of %" PRIu32 - " frames was ignored. Must be %" PRIu32 - " frames or less (44,100 frames per second). " - "Latency remains at %" PRIu32 " frames.", - la, max_frames, conn->latency); + if (config.userSuppliedLatency) { + if (config.userSuppliedLatency != conn->latency) { + debug(1, "Using the user-supplied latency: %" PRIu32 ".", + config.userSuppliedLatency); + } + conn->latency = config.userSuppliedLatency; } else { - // here we have the latency but it does not yet account for the - // audio_backend_latency_offset - int32_t latency_offset = - (int32_t)(config.audio_backend_latency_offset * conn->input_rate); + // It seems that the second pair of bytes in the packet indicate whether a fixed + // delay of 11,025 frames should be added -- iTunes set this field to 7 and + // AirPlay sets it to 4. - // debug(1,"latency offset is %" PRId32 ", input rate is %u", latency_offset, - // conn->input_rate); - int32_t adjusted_latency = latency_offset + (int32_t)la; - if ((adjusted_latency < 0) || - (adjusted_latency > - (int32_t)(conn->max_frames_per_packet * - (BUFFER_FRAMES - config.minimum_free_buffer_headroom)))) - warn("audio_backend_latency_offset out of range -- ignored."); - else - la = adjusted_latency; + // However, on older versions of AirPlay, the 11,025 frames seem to be necessary too - if (la != conn->latency) { - conn->latency = la; - debug(2, - "New latency: %" PRIu32 ", sync latency: %" PRIu32 - ", minimum latency: %" PRIu32 ", maximum " - "latency: %" PRIu32 ", fixed offset: %" PRIu32 - ", audio_backend_latency_offset: %f.", - conn->latency, sync_rtp_timestamp - rtp_timestamp_less_latency, - conn->minimum_latency, conn->maximum_latency, config.fixedLatencyOffset, - config.audio_backend_latency_offset); + // The value of 11,025 (0.25 seconds) is a guess based on the "Audio-Latency" + // parameter + // returned by an AE. + + // Sigh, it would be nice to have a published protocol... + + uint16_t flags = nctohs(&packet[2]); + uint32_t la = sync_rtp_timestamp - rtp_timestamp_less_latency; // note, this might + // loop around in + // modulo. Not sure if + // you'll get an error! + // debug(1, "Latency from the sync packet is %" PRIu32 " frames.", la); + + if ((flags == 7) || ((conn->AirPlayVersion > 0) && (conn->AirPlayVersion <= 353)) || + ((conn->AirPlayVersion > 0) && (conn->AirPlayVersion >= 371))) { + la += config.fixedLatencyOffset; + // debug(1, "Latency offset by %" PRIu32" frames due to the source flags and version + // giving a latency of %" PRIu32 " frames.", config.fixedLatencyOffset, la); + } + if ((conn->maximum_latency) && (conn->maximum_latency < la)) + la = conn->maximum_latency; + if ((conn->minimum_latency) && (conn->minimum_latency > la)) + la = conn->minimum_latency; + + const uint32_t max_frames = ((3 * BUFFER_FRAMES * 352) / 4) - 11025; + + if (la > max_frames) { + warn("An out-of-range latency request of %" PRIu32 + " frames was ignored. Must be %" PRIu32 + " frames or less (44,100 frames per second). " + "Latency remains at %" PRIu32 " frames.", + la, max_frames, conn->latency); + } else { + + // here we have the latency but it does not yet account for the + // audio_backend_latency_offset + int32_t latency_offset = + (int32_t)(config.audio_backend_latency_offset * conn->input_rate); + + // debug(1,"latency offset is %" PRId32 ", input rate is %u", latency_offset, + // conn->input_rate); + int32_t adjusted_latency = latency_offset + (int32_t)la; + if ((adjusted_latency < 0) || + (adjusted_latency > + (int32_t)(conn->max_frames_per_packet * + (BUFFER_FRAMES - config.minimum_free_buffer_headroom)))) + warn("audio_backend_latency_offset out of range -- ignored."); + else + la = adjusted_latency; + + if (la != conn->latency) { + conn->latency = la; + debug(2, + "New latency: %" PRIu32 ", sync latency: %" PRIu32 + ", minimum latency: %" PRIu32 ", maximum " + "latency: %" PRIu32 ", fixed offset: %" PRIu32 + ", audio_backend_latency_offset: %f.", + conn->latency, sync_rtp_timestamp - rtp_timestamp_less_latency, + conn->minimum_latency, conn->maximum_latency, config.fixedLatencyOffset, + config.audio_backend_latency_offset); + } } } - } - // here, we apply the latency to the sync_rtp_timestamp + // here, we apply the latency to the sync_rtp_timestamp - sync_rtp_timestamp = sync_rtp_timestamp - conn->latency; + sync_rtp_timestamp = sync_rtp_timestamp - conn->latency; - debug_mutex_lock(&conn->reference_time_mutex, 1000, 0); + debug_mutex_lock(&conn->reference_time_mutex, 1000, 0); - if (conn->initial_reference_time == 0) { - if (conn->packet_count_since_flush > 0) { - conn->initial_reference_time = remote_time_of_sync; - conn->initial_reference_timestamp = sync_rtp_timestamp; - } - } else { - uint64_t remote_frame_time_interval = - conn->anchor_time - - conn->initial_reference_time; // here, this should never be zero - if (remote_frame_time_interval) { - conn->remote_frame_rate = - (1.0E9 * (conn->anchor_rtptime - conn->initial_reference_timestamp)) / - remote_frame_time_interval; + if (conn->initial_reference_time == 0) { + if (conn->packet_count_since_flush > 0) { + conn->initial_reference_time = remote_time_of_sync; + conn->initial_reference_timestamp = sync_rtp_timestamp; + } } else { - conn->remote_frame_rate = 0.0; // use as a flag. + uint64_t remote_frame_time_interval = + conn->anchor_time - + conn->initial_reference_time; // here, this should never be zero + if (remote_frame_time_interval) { + conn->remote_frame_rate = + (1.0E9 * (conn->anchor_rtptime - conn->initial_reference_timestamp)) / + remote_frame_time_interval; + } else { + conn->remote_frame_rate = 0.0; // use as a flag. + } } + + // this is for debugging + uint64_t old_remote_reference_time = conn->anchor_time; + uint32_t old_reference_timestamp = conn->anchor_rtptime; + // int64_t old_latency_delayed_timestamp = conn->latency_delayed_timestamp; + if (conn->anchor_remote_info_is_valid != 0) { + int64_t time_difference = remote_time_of_sync - conn->anchor_time; + int32_t frame_difference = sync_rtp_timestamp - conn->anchor_rtptime; + double time_difference_in_frames = (1.0 * time_difference * conn->input_rate) / 1000000000; + double frame_change = frame_difference - time_difference_in_frames; + debug(2,"AP1 control thread: set_ntp_anchor_info: rtptime: %" PRIu32 ", networktime: %" PRIx64 ", frame adjustment: %7.3f.", sync_rtp_timestamp, remote_time_of_sync, frame_change); + } else { + debug(2,"AP1 control thread: set_ntp_anchor_info: rtptime: %" PRIu32 ", networktime: %" PRIx64 ".", sync_rtp_timestamp, remote_time_of_sync); + } + + conn->anchor_time = remote_time_of_sync; + // conn->reference_timestamp_time = + // remote_time_of_sync - local_to_remote_time_difference_now(conn); + conn->anchor_rtptime = sync_rtp_timestamp; + conn->anchor_remote_info_is_valid = 1; + + + conn->latency_delayed_timestamp = rtp_timestamp_less_latency; + debug_mutex_unlock(&conn->reference_time_mutex, 0); + + conn->reference_to_previous_time_difference = + remote_time_of_sync - old_remote_reference_time; + if (old_reference_timestamp == 0) + conn->reference_to_previous_frame_difference = 0; + else + conn->reference_to_previous_frame_difference = + sync_rtp_timestamp - old_reference_timestamp; + } else { + debug(2, "Sync packet received before we got a timing packet back."); } + } else if (packet[1] == 0xd6) { // resent audio data in the control path -- whaale only? + pktp = packet + 4; + plen -= 4; + seq_t seqno = ntohs(*(uint16_t *)(pktp + 2)); + debug(3, "Control Receiver -- Retransmitted Audio Data Packet %u received.", seqno); - // this is for debugging - uint64_t old_remote_reference_time = conn->anchor_time; - uint32_t old_reference_timestamp = conn->anchor_rtptime; - // int64_t old_latency_delayed_timestamp = conn->latency_delayed_timestamp; + uint32_t actual_timestamp = ntohl(*(uint32_t *)(pktp + 4)); - conn->anchor_time = remote_time_of_sync; - // conn->reference_timestamp_time = - // remote_time_of_sync - local_to_remote_time_difference_now(conn); - conn->anchor_rtptime = sync_rtp_timestamp; - conn->latency_delayed_timestamp = rtp_timestamp_less_latency; - debug_mutex_unlock(&conn->reference_time_mutex, 0); + pktp += 12; + plen -= 12; - conn->reference_to_previous_time_difference = - remote_time_of_sync - old_remote_reference_time; - if (old_reference_timestamp == 0) - conn->reference_to_previous_frame_difference = 0; - else - conn->reference_to_previous_frame_difference = - sync_rtp_timestamp - old_reference_timestamp; - } else { - debug(2, "Sync packet received before we got a timing packet back."); - } - } else if (packet[1] == 0xd6) { // resent audio data in the control path -- whaale only? - pktp = packet + 4; - plen -= 4; - seq_t seqno = ntohs(*(uint16_t *)(pktp + 2)); - debug(3, "Control Receiver -- Retransmitted Audio Data Packet %u received.", seqno); - - uint32_t actual_timestamp = ntohl(*(uint32_t *)(pktp + 4)); - - pktp += 12; - plen -= 12; - - // check if packet contains enough content to be reasonable - if (plen >= 16) { - player_put_packet(1, seqno, actual_timestamp, pktp, plen, - conn); // the '1' means is original format - continue; - } else { - debug(3, "Too-short retransmitted audio packet received in control port, ignored."); - } - } else - debug(1, "Control Receiver -- Unknown RTP packet of type 0x%02X length %d, ignored.", - packet[1], nread); + // check if packet contains enough content to be reasonable + if (plen >= 16) { + player_put_packet(1, seqno, actual_timestamp, pktp, plen, + conn); // the '1' means is original format + continue; + } else { + debug(3, "Too-short retransmitted audio packet received in control port, ignored."); + } + } else + debug(1, "Control Receiver -- Unknown RTP packet of type 0x%02X length %d, ignored.", + packet[1], nread); + } else { + debug(3, "Control Receiver -- dropping a packet to simulate a bad network."); + } } else { - debug(3, "Control Receiver -- dropping a packet to simulate a bad network."); - } - } else { - char em[1024]; - strerror_r(errno, em, sizeof(em)); - debug(1, "Control Receiver -- error %d receiving a packet: \"%s\".", errno, em); + char em[1024]; + strerror_r(errno, em, sizeof(em)); + debug(1, "Control Receiver -- error %d receiving a packet: \"%s\".", errno, em); + } } } debug(1, "Control RTP thread \"normal\" exit -- this can't happen. Hah!"); @@ -591,42 +605,51 @@ void *rtp_timing_sender(void *arg) { conn->time_ping_count = 0; while (1) { - // debug(1,"Send a timing request"); - - if (!conn->rtp_running) - debug(1, "rtp_timing_sender called without active stream in RTSP conversation thread %d!", - conn->connection_number); - - // debug(1, "Requesting ntp timestamp exchange."); - - req.filler = 0; - req.origin = req.receive = req.transmit = 0; - - conn->departure_time = get_absolute_time_in_ns(); - socklen_t msgsize = sizeof(struct sockaddr_in); -#ifdef AF_INET6 - if (conn->rtp_client_timing_socket.SAFAMILY == AF_INET6) { - msgsize = sizeof(struct sockaddr_in6); - } -#endif - if ((config.diagnostic_drop_packet_fraction == 0.0) || - (drand48() > config.diagnostic_drop_packet_fraction)) { - if (sendto(conn->timing_socket, &req, sizeof(req), 0, - (struct sockaddr *)&conn->rtp_client_timing_socket, msgsize) == -1) { - char em[1024]; - strerror_r(errno, em, sizeof(em)); - debug(1, "Error %d using send-to to the timing socket: \"%s\".", errno, em); + if (conn->rtsp_link_is_idle == 0) { + if (conn->udp_clock_sender_is_initialised == 0) { + request_number = 0; + conn->udp_clock_sender_is_initialised = 1; + debug(2,"AP1 clock sender thread: initialised."); } + // debug(1,"Send a timing request"); + + if (!conn->rtp_running) + debug(1, "rtp_timing_sender called without active stream in RTSP conversation thread %d!", + conn->connection_number); + + // debug(1, "Requesting ntp timestamp exchange."); + + req.filler = 0; + req.origin = req.receive = req.transmit = 0; + + conn->departure_time = get_absolute_time_in_ns(); + socklen_t msgsize = sizeof(struct sockaddr_in); + #ifdef AF_INET6 + if (conn->rtp_client_timing_socket.SAFAMILY == AF_INET6) { + msgsize = sizeof(struct sockaddr_in6); + } + #endif + if ((config.diagnostic_drop_packet_fraction == 0.0) || + (drand48() > config.diagnostic_drop_packet_fraction)) { + if (sendto(conn->timing_socket, &req, sizeof(req), 0, + (struct sockaddr *)&conn->rtp_client_timing_socket, msgsize) == -1) { + char em[1024]; + strerror_r(errno, em, sizeof(em)); + debug(1, "Error %d using send-to to the timing socket: \"%s\".", errno, em); + } + } else { + debug(3, "Timing Sender Thread -- dropping outgoing packet to simulate bad network."); + } + + request_number++; + + if (request_number <= 3) + usleep(300000); // these are thread cancellation points + else + usleep(3000000); } else { - debug(3, "Timing Sender Thread -- dropping outgoing packet to simulate bad network."); + usleep(100000); // wait until sleep is over } - - request_number++; - - if (request_number <= 6) - usleep(300000); // these are thread cancellation points - else - usleep(3000000); } debug(3, "rtp_timing_sender thread interrupted. This should never happen."); pthread_cleanup_pop(0); // don't execute anything here. @@ -682,8 +705,6 @@ void *rtp_timing_receiver(void *arg) { uint64_t distant_receive_time, distant_transmit_time, arrival_time, return_time; local_to_remote_time_jitter = 0; local_to_remote_time_jitter_count = 0; - // uint64_t first_remote_time = 0; - // uint64_t first_local_time = 0; uint64_t first_local_to_remote_time_difference = 0; @@ -727,222 +748,234 @@ void *rtp_timing_receiver(void *arg) { while (1) { nread = recv(conn->timing_socket, packet, sizeof(packet), 0); + if (conn->rtsp_link_is_idle == 0) { + if (conn->udp_clock_is_initialised == 0) { + debug(2,"AP1 clock receiver thread: initialised."); + local_to_remote_time_jitter = 0; + local_to_remote_time_jitter_count = 0; - if (nread >= 0) { + first_local_to_remote_time_difference = 0; - if ((config.diagnostic_drop_packet_fraction == 0.0) || - (drand48() > config.diagnostic_drop_packet_fraction)) { - arrival_time = get_absolute_time_in_ns(); + sequence_number = 0; + stat_n = 0; + stat_mean = 0.0; + conn->udp_clock_is_initialised = 1; + } + if (nread >= 0) { + if ((config.diagnostic_drop_packet_fraction == 0.0) || + (drand48() > config.diagnostic_drop_packet_fraction)) { + arrival_time = get_absolute_time_in_ns(); - // ssize_t plen = nread; - // debug(1,"Packet Received on Timing Port."); - if (packet[1] == 0xd3) { // timing reply + // ssize_t plen = nread; + // debug(1,"Packet Received on Timing Port."); + if (packet[1] == 0xd3) { // timing reply - return_time = arrival_time - conn->departure_time; - debug(2, "clock synchronisation request: return time is %8.3f milliseconds.", - 0.000001 * return_time); + return_time = arrival_time - conn->departure_time; + debug(2, "clock synchronisation request: return time is %8.3f milliseconds.", + 0.000001 * return_time); - if (return_time < 200000000) { // must be less than 0.2 seconds - // distant_receive_time = - // ((uint64_t)ntohl(*((uint32_t*)&packet[16])))<<32+ntohl(*((uint32_t*)&packet[20])); + if (return_time < 200000000) { // must be less than 0.2 seconds + // distant_receive_time = + // ((uint64_t)ntohl(*((uint32_t*)&packet[16])))<<32+ntohl(*((uint32_t*)&packet[20])); - uint64_t ps, pn; + uint64_t ps, pn; - ps = nctohl(&packet[16]); - ps = ps * 1000000000; // this many nanoseconds from the whole seconds - pn = nctohl(&packet[20]); - pn = pn * 1000000000; - pn = pn >> 32; // this many nanoseconds from the fractional part - distant_receive_time = ps + pn; + ps = nctohl(&packet[16]); + ps = ps * 1000000000; // this many nanoseconds from the whole seconds + pn = nctohl(&packet[20]); + pn = pn * 1000000000; + pn = pn >> 32; // this many nanoseconds from the fractional part + distant_receive_time = ps + pn; - // distant_transmit_time = - // ((uint64_t)ntohl(*((uint32_t*)&packet[24])))<<32+ntohl(*((uint32_t*)&packet[28])); + // distant_transmit_time = + // ((uint64_t)ntohl(*((uint32_t*)&packet[24])))<<32+ntohl(*((uint32_t*)&packet[28])); - ps = nctohl(&packet[24]); - ps = ps * 1000000000; // this many nanoseconds from the whole seconds - pn = nctohl(&packet[28]); - pn = pn * 1000000000; - pn = pn >> 32; // this many nanoseconds from the fractional part - distant_transmit_time = ps + pn; + ps = nctohl(&packet[24]); + ps = ps * 1000000000; // this many nanoseconds from the whole seconds + pn = nctohl(&packet[28]); + pn = pn * 1000000000; + pn = pn >> 32; // this many nanoseconds from the fractional part + distant_transmit_time = ps + pn; - uint64_t remote_processing_time = 0; + uint64_t remote_processing_time = 0; - if (distant_transmit_time >= distant_receive_time) - remote_processing_time = distant_transmit_time - distant_receive_time; - else { - debug(1, "Yikes: distant_transmit_time is before distant_receive_time; remote " - "processing time set to zero."); - } - // debug(1,"Return trip time: %" PRIu64 " nS, remote processing time: %" PRIu64 " - // nS.",return_time, remote_processing_time); - - if (remote_processing_time < return_time) - return_time -= remote_processing_time; - else - debug(1, "Remote processing time greater than return time -- ignored."); - - int cc; - // debug(1, "time ping history is %d entries.", time_ping_history); - for (cc = time_ping_history - 1; cc > 0; cc--) { - conn->time_pings[cc] = conn->time_pings[cc - 1]; - // if ((conn->time_ping_count) && (conn->time_ping_count < 10)) - // conn->time_pings[cc].dispersion = - // conn->time_pings[cc].dispersion * pow(2.14, - // 1.0/conn->time_ping_count); - if (conn->time_pings[cc].dispersion > UINT64_MAX / dispersion_factor) - debug(1, "dispersion factor is too large at %" PRIu64 "."); - else - conn->time_pings[cc].dispersion = - (conn->time_pings[cc].dispersion * dispersion_factor) / - 100; // make the dispersions 'age' by this rational factor - } - // these are used for doing a least squares calculation to get the drift - conn->time_pings[0].local_time = arrival_time; - conn->time_pings[0].remote_time = distant_transmit_time + return_time / 2; - conn->time_pings[0].sequence_number = sequence_number++; - conn->time_pings[0].chosen = 0; - conn->time_pings[0].dispersion = return_time; - if (conn->time_ping_count < time_ping_history) - conn->time_ping_count++; - - // here, calculate the mean and standard deviation of the return times - - // mean and variance calculations from "online_variance" algorithm at - // https://en.wikipedia.org/wiki/Algorithms_for_calculating_variance#Online_algorithm - - stat_n += 1; - double stat_delta = return_time - stat_mean; - stat_mean += stat_delta / stat_n; - // stat_M2 += stat_delta * (return_time - stat_mean); - // debug(1, "Timing packet return time stats: current, mean and standard deviation over - // %d packets: %.1f, %.1f, %.1f (nanoseconds).", - // stat_n,return_time,stat_mean, sqrtf(stat_M2 / (stat_n - 1))); - - // here, pick the record with the least dispersion, and record that it's been chosen - - // uint64_t local_time_chosen = arrival_time; - // uint64_t remote_time_chosen = distant_transmit_time; - // now pick the timestamp with the lowest dispersion - uint64_t rt = conn->time_pings[0].remote_time; - uint64_t lt = conn->time_pings[0].local_time; - uint64_t tld = conn->time_pings[0].dispersion; - int chosen = 0; - for (cc = 1; cc < conn->time_ping_count; cc++) - if (conn->time_pings[cc].dispersion < tld) { - chosen = cc; - rt = conn->time_pings[cc].remote_time; - lt = conn->time_pings[cc].local_time; - tld = conn->time_pings[cc].dispersion; - // local_time_chosen = conn->time_pings[cc].local_time; - // remote_time_chosen = conn->time_pings[cc].remote_time; - } - // debug(1,"Record %d has the lowest dispersion with %0.2f us - // dispersion.",chosen,1.0*((tld * 1000000) >> 32)); - conn->time_pings[chosen].chosen = 1; // record the fact that it has been used for timing - - conn->local_to_remote_time_difference = - rt - lt; // make this the new local-to-remote-time-difference - conn->local_to_remote_time_difference_measurement_time = lt; // done at this time. - - if (first_local_to_remote_time_difference == 0) { - first_local_to_remote_time_difference = conn->local_to_remote_time_difference; - // first_local_to_remote_time_difference_time = get_absolute_time_in_fp(); - } - - // here, let's try to use the timing pings that were selected because of their short - // return times to - // estimate a figure for drift between the local clock (x) and the remote clock (y) - - // if we plug in a local interval, we will get back what that is in remote time - - // calculate the line of best fit for relating the local time and the remote time - // we will calculate the slope, which is the drift - // see https://www.varsitytutors.com/hotmath/hotmath_help/topics/line-of-best-fit - - uint64_t y_bar = 0; // remote timestamp average - uint64_t x_bar = 0; // local timestamp average - int sample_count = 0; - - // approximate time in seconds to let the system settle down - const int settling_time = 60; - // number of points to have for calculating a valid drift - const int sample_point_minimum = 8; - for (cc = 0; cc < conn->time_ping_count; cc++) - if ((conn->time_pings[cc].chosen) && - (conn->time_pings[cc].sequence_number > - (settling_time / 3))) { // wait for a approximate settling time - // have to scale them down so that the sum, possibly over - // every term in the array, doesn't overflow - y_bar += (conn->time_pings[cc].remote_time >> time_ping_history_power_of_two); - x_bar += (conn->time_pings[cc].local_time >> time_ping_history_power_of_two); - sample_count++; - } - conn->local_to_remote_time_gradient_sample_count = sample_count; - if (sample_count > sample_point_minimum) { - y_bar = y_bar / sample_count; - x_bar = x_bar / sample_count; - - int64_t xid, yid; - double mtl, mbl; - mtl = 0; - mbl = 0; - for (cc = 0; cc < conn->time_ping_count; cc++) - if ((conn->time_pings[cc].chosen) && - (conn->time_pings[cc].sequence_number > (settling_time / 3))) { - - uint64_t slt = conn->time_pings[cc].local_time >> time_ping_history_power_of_two; - if (slt > x_bar) - xid = slt - x_bar; - else - xid = -(x_bar - slt); - - uint64_t srt = conn->time_pings[cc].remote_time >> time_ping_history_power_of_two; - if (srt > y_bar) - yid = srt - y_bar; - else - yid = -(y_bar - srt); - - mtl = mtl + (1.0 * xid) * yid; - mbl = mbl + (1.0 * xid) * xid; - } - if (mbl) - conn->local_to_remote_time_gradient = mtl / mbl; + if (distant_transmit_time >= distant_receive_time) + remote_processing_time = distant_transmit_time - distant_receive_time; else { - // conn->local_to_remote_time_gradient = 1.0; - debug(1, "mbl is zero. Drift remains at %.2f ppm.", - (conn->local_to_remote_time_gradient - 1.0) * 1000000); + debug(1, "Yikes: distant_transmit_time is before distant_receive_time; remote " + "processing time set to zero."); } + // debug(1,"Return trip time: %" PRIu64 " nS, remote processing time: %" PRIu64 " + // nS.",return_time, remote_processing_time); - // scale the numbers back up - uint64_t ybf = y_bar << time_ping_history_power_of_two; - uint64_t xbf = x_bar << time_ping_history_power_of_two; + if (remote_processing_time < return_time) + return_time -= remote_processing_time; + else + debug(1, "Remote processing time greater than return time -- ignored."); + + int cc; + // debug(1, "time ping history is %d entries.", time_ping_history); + for (cc = time_ping_history - 1; cc > 0; cc--) { + conn->time_pings[cc] = conn->time_pings[cc - 1]; + // if ((conn->time_ping_count) && (conn->time_ping_count < 10)) + // conn->time_pings[cc].dispersion = + // conn->time_pings[cc].dispersion * pow(2.14, + // 1.0/conn->time_ping_count); + if (conn->time_pings[cc].dispersion > UINT64_MAX / dispersion_factor) + debug(1, "dispersion factor is too large at %" PRIu64 "."); + else + conn->time_pings[cc].dispersion = + (conn->time_pings[cc].dispersion * dispersion_factor) / + 100; // make the dispersions 'age' by this rational factor + } + // these are used for doing a least squares calculation to get the drift + conn->time_pings[0].local_time = arrival_time; + conn->time_pings[0].remote_time = distant_transmit_time + return_time / 2; + conn->time_pings[0].sequence_number = sequence_number++; + conn->time_pings[0].chosen = 0; + conn->time_pings[0].dispersion = return_time; + if (conn->time_ping_count < time_ping_history) + conn->time_ping_count++; + + // here, calculate the mean and standard deviation of the return times + + // mean and variance calculations from "online_variance" algorithm at + // https://en.wikipedia.org/wiki/Algorithms_for_calculating_variance#Online_algorithm + + stat_n += 1; + double stat_delta = return_time - stat_mean; + stat_mean += stat_delta / stat_n; + // stat_M2 += stat_delta * (return_time - stat_mean); + // debug(1, "Timing packet return time stats: current, mean and standard deviation over + // %d packets: %.1f, %.1f, %.1f (nanoseconds).", + // stat_n,return_time,stat_mean, sqrtf(stat_M2 / (stat_n - 1))); + + // here, pick the record with the least dispersion, and record that it's been chosen + + // uint64_t local_time_chosen = arrival_time; + // uint64_t remote_time_chosen = distant_transmit_time; + // now pick the timestamp with the lowest dispersion + uint64_t rt = conn->time_pings[0].remote_time; + uint64_t lt = conn->time_pings[0].local_time; + uint64_t tld = conn->time_pings[0].dispersion; + int chosen = 0; + for (cc = 1; cc < conn->time_ping_count; cc++) + if (conn->time_pings[cc].dispersion < tld) { + chosen = cc; + rt = conn->time_pings[cc].remote_time; + lt = conn->time_pings[cc].local_time; + tld = conn->time_pings[cc].dispersion; + // local_time_chosen = conn->time_pings[cc].local_time; + // remote_time_chosen = conn->time_pings[cc].remote_time; + } + // debug(1,"Record %d has the lowest dispersion with %0.2f us + // dispersion.",chosen,1.0*((tld * 1000000) >> 32)); + conn->time_pings[chosen].chosen = 1; // record the fact that it has been used for timing conn->local_to_remote_time_difference = - ybf - xbf; // make this the new local-to-remote-time-difference - conn->local_to_remote_time_difference_measurement_time = xbf; + rt - lt; // make this the new local-to-remote-time-difference + conn->local_to_remote_time_difference_measurement_time = lt; // done at this time. + if (first_local_to_remote_time_difference == 0) { + first_local_to_remote_time_difference = conn->local_to_remote_time_difference; + // first_local_to_remote_time_difference_time = get_absolute_time_in_fp(); + } + + // here, let's try to use the timing pings that were selected because of their short + // return times to + // estimate a figure for drift between the local clock (x) and the remote clock (y) + + // if we plug in a local interval, we will get back what that is in remote time + + // calculate the line of best fit for relating the local time and the remote time + // we will calculate the slope, which is the drift + // see https://www.varsitytutors.com/hotmath/hotmath_help/topics/line-of-best-fit + + uint64_t y_bar = 0; // remote timestamp average + uint64_t x_bar = 0; // local timestamp average + int sample_count = 0; + + // approximate time in seconds to let the system settle down + const int settling_time = 60; + // number of points to have for calculating a valid drift + const int sample_point_minimum = 8; + for (cc = 0; cc < conn->time_ping_count; cc++) + if ((conn->time_pings[cc].chosen) && + (conn->time_pings[cc].sequence_number > + (settling_time / 3))) { // wait for a approximate settling time + // have to scale them down so that the sum, possibly over + // every term in the array, doesn't overflow + y_bar += (conn->time_pings[cc].remote_time >> time_ping_history_power_of_two); + x_bar += (conn->time_pings[cc].local_time >> time_ping_history_power_of_two); + sample_count++; + } + conn->local_to_remote_time_gradient_sample_count = sample_count; + if (sample_count > sample_point_minimum) { + y_bar = y_bar / sample_count; + x_bar = x_bar / sample_count; + + int64_t xid, yid; + double mtl, mbl; + mtl = 0; + mbl = 0; + for (cc = 0; cc < conn->time_ping_count; cc++) + if ((conn->time_pings[cc].chosen) && + (conn->time_pings[cc].sequence_number > (settling_time / 3))) { + + uint64_t slt = conn->time_pings[cc].local_time >> time_ping_history_power_of_two; + if (slt > x_bar) + xid = slt - x_bar; + else + xid = -(x_bar - slt); + + uint64_t srt = conn->time_pings[cc].remote_time >> time_ping_history_power_of_two; + if (srt > y_bar) + yid = srt - y_bar; + else + yid = -(y_bar - srt); + + mtl = mtl + (1.0 * xid) * yid; + mbl = mbl + (1.0 * xid) * xid; + } + if (mbl) + conn->local_to_remote_time_gradient = mtl / mbl; + else { + // conn->local_to_remote_time_gradient = 1.0; + debug(1, "mbl is zero. Drift remains at %.2f ppm.", + (conn->local_to_remote_time_gradient - 1.0) * 1000000); + } + + // scale the numbers back up + uint64_t ybf = y_bar << time_ping_history_power_of_two; + uint64_t xbf = x_bar << time_ping_history_power_of_two; + + conn->local_to_remote_time_difference = + ybf - xbf; // make this the new local-to-remote-time-difference + conn->local_to_remote_time_difference_measurement_time = xbf; + + } else { + debug(3, "not enough samples to estimate drift -- remaining at %.2f ppm.", + (conn->local_to_remote_time_gradient - 1.0) * 1000000); + // conn->local_to_remote_time_gradient = 1.0; + } + // debug(1,"local to remote time gradient is %12.2f ppm, based on %d + // samples.",conn->local_to_remote_time_gradient*1000000,sample_count); + // debug(1,"ntp set offset and measurement time"); // iin PTP terms, this is the local-to-network offset and the local measurement time } else { - debug(3, "not enough samples to estimate drift -- remaining at %.2f ppm.", - (conn->local_to_remote_time_gradient - 1.0) * 1000000); - // conn->local_to_remote_time_gradient = 1.0; + debug(1, + "Time ping turnaround time: %" PRIu64 + " ns -- it looks like a timing ping was lost.", + return_time); } - // debug(1,"local to remote time gradient is %12.2f ppm, based on %d - // samples.",conn->local_to_remote_time_gradient*1000000,sample_count); - } else { - debug(1, - "Time ping turnaround time: %" PRIu64 - " ns -- it looks like a timing ping was lost.", - return_time); + debug(1, "Timing port -- Unknown RTP packet of type 0x%02X length %d.", packet[1], nread); } } else { - debug(1, "Timing port -- Unknown RTP packet of type 0x%02X length %d.", packet[1], nread); + debug(3, "Timing Receiver Thread -- dropping incoming packet to simulate a bad network."); } } else { - debug(3, "Timing Receiver Thread -- dropping incoming packet to simulate a bad network."); + debug(1, "Timing receiver -- error receiving a packet."); } - } else { - debug(1, "Timing receiver -- error receiving a packet."); } } @@ -1070,111 +1103,70 @@ void rtp_setup(SOCKADDR *local, SOCKADDR *remote, uint16_t cport, uint16_t tport void reset_ntp_anchor_info(rtsp_conn_info *conn) { debug_mutex_lock(&conn->reference_time_mutex, 1000, 1); + conn->anchor_remote_info_is_valid = 0; conn->anchor_rtptime = 0; conn->anchor_time = 0; debug_mutex_unlock(&conn->reference_time_mutex, 3); } -int have_ntp_timestamp_timing_information(rtsp_conn_info *conn) { - if (conn->anchor_rtptime == 0) - return 0; - else +int have_ntp_timing_information(rtsp_conn_info *conn) { + if (conn->anchor_remote_info_is_valid != 0) return 1; -} - -// set this to zero to use the rates supplied by the sources, which might not always be completely -// right... -const int use_nominal_rate = 0; // specify whether to use the nominal input rate, usually 44100 fps - -int sanitised_source_rate_information(uint32_t *frames, uint64_t *time, rtsp_conn_info *conn) { - int result = 1; - if (conn->input_rate == 0) - die("conn->input_rate is zero!"); - uint32_t fs = conn->input_rate; - *frames = fs; // default value to return - *time = 1000000000; // default value to return - if ((conn->initial_reference_time) && (conn->initial_reference_timestamp)) { - // uint32_t local_frames = conn->reference_timestamp - conn->initial_reference_timestamp; - uint32_t local_frames = - modulo_32_offset(conn->initial_reference_timestamp, conn->anchor_rtptime); - uint64_t local_time = conn->anchor_time - conn->initial_reference_time; - if ((local_frames == 0) || (local_time == 0) || (use_nominal_rate)) { - result = 1; - } else { - double calculated_frame_rate = conn->input_rate; - if (local_time) - calculated_frame_rate = (1.0E9 * local_frames) / local_time; - else - debug(1, "sanitised_source_rate_information: local_time is zero"); - if ((local_time == 0) || ((calculated_frame_rate / conn->input_rate) > 1.002) || - ((calculated_frame_rate / conn->input_rate) < 0.998)) { - debug(3, "input frame rate out of bounds at %.2f fps.", calculated_frame_rate); - result = 1; - } else { - *frames = local_frames; - if (local_frames == 0) - die("local_frames is zero!"); - *time = local_time; - if (local_time == 0) - die("local_time is zero!"); - result = 0; - } - } - } - return result; -} - -void set_ntp_anchor_info(rtsp_conn_info *conn, uint32_t rtptime, uint64_t networktime) { - conn->anchor_remote_info_is_valid = 1; - conn->anchor_rtptime = rtptime; - conn->anchor_time = networktime; + else + return 0; } // the timestamp is a timestamp calculated at the input rate // the reference timestamps are denominated in terms of the input rate int frame_to_ntp_local_time(uint32_t timestamp, uint64_t *time, rtsp_conn_info *conn) { + // a zero result is good + if (conn->anchor_remote_info_is_valid == 0) + debug(1,"no anchor information"); debug_mutex_lock(&conn->reference_time_mutex, 1000, 0); - int result = 0; - uint64_t time_difference; - uint32_t frame_difference; - result = sanitised_source_rate_information(&frame_difference, &time_difference, conn); - - uint64_t remote_time_of_timestamp; - int32_t timestamp_interval = timestamp - conn->anchor_rtptime; - int64_t timestamp_interval_time = timestamp_interval; - timestamp_interval_time = timestamp_interval_time * time_difference; - timestamp_interval_time = - timestamp_interval_time / frame_difference; // this is the nominal time, based on the - // fps specified between current and - // previous sync frame. - remote_time_of_timestamp = - conn->anchor_time + timestamp_interval_time; // based on the reference timestamp time - // plus the time interval calculated based - // on the specified fps. - *time = remote_time_of_timestamp - local_to_remote_time_difference_now(conn); + int result = -1; + if (conn->anchor_remote_info_is_valid != 0) { + uint64_t remote_time_of_timestamp; + int32_t timestamp_interval = timestamp - conn->anchor_rtptime; + int64_t timestamp_interval_time = timestamp_interval; + timestamp_interval_time = timestamp_interval_time * 1000000000; + timestamp_interval_time = + timestamp_interval_time / 44100; // this is the nominal time, based on the + // fps specified between current and + // previous sync frame. + remote_time_of_timestamp = + conn->anchor_time + timestamp_interval_time; // based on the reference timestamp time + // plus the time interval calculated based + // on the specified fps. + if (time != NULL) + *time = remote_time_of_timestamp - local_to_remote_time_difference_now(conn); + result = 0; + } debug_mutex_unlock(&conn->reference_time_mutex, 0); return result; } int local_ntp_time_to_frame(uint64_t time, uint32_t *frame, rtsp_conn_info *conn) { + // a zero result is good debug_mutex_lock(&conn->reference_time_mutex, 1000, 0); - int result = 0; - uint64_t time_difference; - uint32_t frame_difference; - result = sanitised_source_rate_information(&frame_difference, &time_difference, conn); - // first, get from [local] time to remote time. - uint64_t remote_time = time + local_to_remote_time_difference_now(conn); - // next, get the remote time interval from the remote_time to the reference time - // here, we calculate the time interval, in terms of remote time - int64_t offset = remote_time - conn->anchor_time; - // now, convert the remote time interval into frames using the frame rate we have observed or - // which has been nominated - int64_t frame_interval = 0; - frame_interval = (offset * frame_difference) / time_difference; - int32_t frame_interval_32 = frame_interval; - uint32_t new_frame = conn->anchor_rtptime + frame_interval_32; - *frame = new_frame; + int result = -1; + if (conn->anchor_remote_info_is_valid != 0) { + // first, get from [local] time to remote time. + uint64_t remote_time = time + local_to_remote_time_difference_now(conn); + // next, get the remote time interval from the remote_time to the reference time + // here, we calculate the time interval, in terms of remote time + int64_t offset = remote_time - conn->anchor_time; + // now, convert the remote time interval into frames using the frame rate we have observed or + // which has been nominated + int64_t frame_interval = 0; + frame_interval = (offset * 44100) / 1000000000; + int32_t frame_interval_32 = frame_interval; + uint32_t new_frame = conn->anchor_rtptime + frame_interval_32; + // debug(1,"frame is %u.", new_frame); + if (frame != NULL) + *frame = new_frame; + result = 0; + } debug_mutex_unlock(&conn->reference_time_mutex, 0); return result; } @@ -1338,71 +1330,74 @@ void reset_ptp_anchor_info(rtsp_conn_info *conn) { int long_time_notifcation_done = 0; int get_ptp_anchor_local_time_info(rtsp_conn_info *conn, uint32_t *anchorRTP, uint64_t *anchorLocalTime) { - uint64_t actual_clock_id, actual_time_of_sample, actual_offset, start_of_mastership; - int response = ptp_get_clock_info(&actual_clock_id, &actual_time_of_sample, &actual_offset, - &start_of_mastership); - - if (response == clock_ok) { - uint64_t time_now = get_absolute_time_in_ns(); - int64_t time_since_sample = time_now - actual_time_of_sample; - if (time_since_sample > 300000000000) { - if (long_time_notifcation_done == 0) { - debug(1, "The last PTP timing sample is pretty old: %f seconds.", - 0.000000001 * time_since_sample); - long_time_notifcation_done = 1; - } - } else if ((time_since_sample < 2000000000) && (long_time_notifcation_done != 0)) { - debug(1, "The last PTP timing sample is no longer too old: %f seconds.", - 0.000000001 * time_since_sample); - long_time_notifcation_done = 0; - } - - if (conn->anchor_remote_info_is_valid != - 0) { // i.e. if we have anchor clock ID and anchor time / rtptime - - if (actual_clock_id == conn->anchor_clock) { - conn->last_anchor_rtptime = conn->anchor_rtptime; - conn->last_anchor_local_time = conn->anchor_time - actual_offset; - conn->last_anchor_time_of_update = time_now; - if (conn->last_anchor_info_is_valid == 0) - conn->last_anchor_validity_start_time = start_of_mastership; - conn->last_anchor_info_is_valid = 1; - } else { - debug(3, "Current master clock %" PRIx64 " and anchor_clock %" PRIx64 " are different", - actual_clock_id, conn->anchor_clock); - // the anchor clock and the actual clock are different - - if (conn->last_anchor_info_is_valid != 0) { - - int64_t time_since_last_update = - get_absolute_time_in_ns() - conn->last_anchor_time_of_update; - if (time_since_last_update > 5000000000) { - int64_t duration_of_mastership = time_now - start_of_mastership; - debug(2, - "Connection %d: Master clock has changed to %" PRIx64 - ". History: %.3f milliseconds.", - conn->connection_number, actual_clock_id, 0.000001 * duration_of_mastership); - - // Now, the thing is that while the anchor clock and master clock for a - // buffered session start off the same, - // the master clock can change without the anchor clock changing. - // SPS gives the new master clock time to settle down and then - // calculates the appropriate offset to it by - // calculating back from the local anchor information and the new clock's - // advertised offset. - - conn->anchor_time = conn->last_anchor_local_time + actual_offset; - conn->anchor_clock = actual_clock_id; - - } - - } else { - response = clock_not_valid; // no current clock information and no previous clock info + int response = clock_not_valid; + uint64_t actual_clock_id; + if (conn->rtsp_link_is_idle == 0) { + uint64_t actual_time_of_sample, actual_offset, start_of_mastership; + response = ptp_get_clock_info(&actual_clock_id, &actual_time_of_sample, &actual_offset, + &start_of_mastership); + if (response == clock_ok) { + uint64_t time_now = get_absolute_time_in_ns(); + int64_t time_since_sample = time_now - actual_time_of_sample; + if (time_since_sample > 300000000000) { + if (long_time_notifcation_done == 0) { + debug(1, "The last PTP timing sample is pretty old: %f seconds.", + 0.000000001 * time_since_sample); + long_time_notifcation_done = 1; } + } else if ((time_since_sample < 2000000000) && (long_time_notifcation_done != 0)) { + debug(1, "The last PTP timing sample is no longer too old: %f seconds.", + 0.000000001 * time_since_sample); + long_time_notifcation_done = 0; + } + + if (conn->anchor_remote_info_is_valid != + 0) { // i.e. if we have anchor clock ID and anchor time / rtptime + + if (actual_clock_id == conn->anchor_clock) { + conn->last_anchor_rtptime = conn->anchor_rtptime; + conn->last_anchor_local_time = conn->anchor_time - actual_offset; + conn->last_anchor_time_of_update = time_now; + if (conn->last_anchor_info_is_valid == 0) + conn->last_anchor_validity_start_time = start_of_mastership; + conn->last_anchor_info_is_valid = 1; + } else { + debug(3, "Current master clock %" PRIx64 " and anchor_clock %" PRIx64 " are different", + actual_clock_id, conn->anchor_clock); + // the anchor clock and the actual clock are different + + if (conn->last_anchor_info_is_valid != 0) { + + int64_t time_since_last_update = + get_absolute_time_in_ns() - conn->last_anchor_time_of_update; + if (time_since_last_update > 5000000000) { + int64_t duration_of_mastership = time_now - start_of_mastership; + debug(2, + "Connection %d: Master clock has changed to %" PRIx64 + ". History: %.3f milliseconds.", + conn->connection_number, actual_clock_id, 0.000001 * duration_of_mastership); + + // Now, the thing is that while the anchor clock and master clock for a + // buffered session start off the same, + // the master clock can change without the anchor clock changing. + // SPS gives the new master clock time to settle down and then + // calculates the appropriate offset to it by + // calculating back from the local anchor information and the new clock's + // advertised offset. + + conn->anchor_time = conn->last_anchor_local_time + actual_offset; + conn->anchor_clock = actual_clock_id; + + } + + } else { + response = clock_not_valid; // no current clock information and no previous clock info + } + } + } else { + // debug(1, "anchor_remote_info_is_valid not valid"); + response = clock_no_anchor_info; // no anchor information } - } else { - // debug(1, "anchor_remote_info_is_valid not valid"); - response = clock_no_anchor_info; // no anchor information } } @@ -1443,7 +1438,7 @@ int get_ptp_anchor_local_time_info(rtsp_conn_info *conn, uint32_t *anchorRTP, debug(1, "Connection %d: NQPTP clock is not synchronised.", conn->connection_number); break; case clock_not_valid: - debug(1, "Connection %d: NQPTP clock information is not valid.", conn->connection_number); + debug(2, "Connection %d: NQPTP clock information is not valid.", conn->connection_number); break; default: debug(1, "Connection %d: NQPTP clock reports an unrecognised status: %u.", @@ -1485,7 +1480,7 @@ int frame_to_ptp_local_time(uint32_t timestamp, uint64_t *time, rtsp_conn_info * *time = ltime; result = 0; } else { - debug(3, "frame_to_local_time can't get anchor local time information"); + debug(3, "frame_to_ptp_local_time can't get anchor local time information"); } return result; } @@ -1504,7 +1499,7 @@ int local_ptp_time_to_frame(uint64_t time, uint32_t *frame, rtsp_conn_info *conn *frame = lframe; result = 0; } else { - debug(3, "local_time_to_frame can't get anchor local time information"); + debug(3, "local_ptp_time_to_frame can't get anchor local time information"); } return result; } @@ -1706,6 +1701,7 @@ int32_t decipher_player_put_packet(uint8_t *ciphered_audio_alt, ssize_t nread, if (new_payload_length > max_int) debug(1, "Madly long payload length!"); int plen = new_payload_length; // + // debug(1," Write packet to buffer %d, timestamp %u.", sequence_number, timestamp); player_put_packet(1, sequence_number, timestamp, m, plen, conn); // the '1' means is original format return sequence_number; @@ -1728,155 +1724,157 @@ void *rtp_ap2_control_receiver(void *arg) { socklen_t from_sock_addr_length = sizeof(SOCKADDR); memset(&from_sock_addr, 0, sizeof(SOCKADDR)); - - struct timeval tv; - tv.tv_sec = 7; // wait this many seconds for a packet, which should come every two seconds - tv.tv_usec = 0; - setsockopt(conn->ap2_control_socket, SOL_SOCKET, SO_RCVTIMEO, (const char*)&tv, sizeof tv); - - nread = recvfrom(conn->ap2_control_socket, packet, sizeof(packet), 0, (struct sockaddr *)&from_sock_addr, &from_sock_addr_length); uint64_t time_now = get_absolute_time_in_ns(); int64_t time_since_start = time_now - start_time; - // debug(1,"Connection %d: AP2 Control Packet received.", conn->connection_number); - - if (nread >= 28) { // must have at least 28 bytes for the timing information - if ((time_since_start < 2000000) && ((packet[0] & 0x10) == 0)) { - debug(1, - "Dropping what looks like a (non-sentinel) packet left over from a previous session " - "at %f ms.", - 0.000001 * time_since_start); - } else { - packet_number++; - - if (packet_number == 1) { - if ((packet[0] & 0x10) != 0) { - debug(2, "First packet is a sentinel packet."); - } else { - debug(2, "First packet is a not a sentinel packet!"); - } - } - // debug(1,"rtp_ap2_control_receiver coded: %u, %u", packet[0], packet[1]); - if (packet_number >= 2) { - if ((config.diagnostic_drop_packet_fraction == 0.0) || - (drand48() > config.diagnostic_drop_packet_fraction)) { - // store the from_sock_addr if we haven't already done so - // v remember to zero this when you're finished! - if (conn->ap2_remote_control_socket_addr_length == 0) { - memcpy(&conn->ap2_remote_control_socket_addr, &from_sock_addr, from_sock_addr_length); - conn->ap2_remote_control_socket_addr_length = from_sock_addr_length; - } - switch (packet[1]) { - case 215: // code 215, effectively an anchoring announcement - { - // struct timespec tnr; - // clock_gettime(CLOCK_REALTIME, &tnr); - // uint64_t local_realtime_now = timespec_to_ns(&tnr); - - /* - char obf[4096]; - char *obfp = obf; - int obfc; - for (obfc=0;obfcinput_rate); - // the actual latency is the notified latency plus the fixed latency + the added latency - - int32_t net_latency = - notified_latency + 11035 + - added_latency; // this is the latency between incoming frames and the DAC - net_latency = net_latency - - (int32_t)(config.audio_backend_buffer_desired_length * conn->input_rate); - // debug(1, "Net latency is %d frames.", net_latency); - - if (net_latency <= 0) { - if (conn->latency_warning_issued == 0) { - warn("The stream latency (%f seconds) it too short to accommodate an offset of %f " - "seconds and a backend buffer of %f seconds.", - ((notified_latency + 11035) * 1.0) / conn->input_rate, - config.audio_backend_latency_offset, - config.audio_backend_buffer_desired_length); - warn("(FYI the stream latency needed would be %f seconds.)", - config.audio_backend_buffer_desired_length - - config.audio_backend_latency_offset); - conn->latency_warning_issued = 1; - } - conn->latency = notified_latency + 11035; - } else { - conn->latency = notified_latency + 11035 + added_latency; - } - - set_ptp_anchor_info(conn, clock_id, frame_1 - 11035 - added_latency, - remote_packet_time_ns); - if (conn->anchor_clock != clock_id) { - debug(2, "Connection %d: Change Anchor Clock: %" PRIx64 ".", conn->connection_number, - clock_id); - } - - } break; - case 0xd6: - // six bytes in is the sequence number at the start of the encrypted audio packet - // returns the sequence number but we're not really interested - decipher_player_put_packet(packet + 6, nread - 6, conn); - break; - default: { - char *packet_in_hex_cstring = - debug_malloc_hex_cstring(packet, nread); // remember to free this afterwards - debug( - 1, - "AP2 Control Receiver Packet of first byte 0x%02X, type 0x%02X length %d received: " - "\"%s\".", - packet[0], packet[1], nread, packet_in_hex_cstring); - free(packet_in_hex_cstring); - } break; - } - - } else { - debug(1, "AP2 Control Receiver -- dropping a packet."); - } - } + if (conn->rtsp_link_is_idle == 0) { + if (conn->udp_clock_is_initialised == 0) { + packet_number = 0; + conn->udp_clock_is_initialised = 1; + debug(1,"AP2 Realtime Clock receiver initialised."); } - } else { - if (nread == -1) { - if ((errno == EAGAIN) || (errno == EWOULDBLOCK)) { - if (conn->airplay_stream_type == realtime_stream) { - debug(2, "Connection %d: no control packets for the last 10 seconds -- resetting anchor info", conn->connection_number); - reset_ptp_anchor_info(conn); - packet_number = 0; // start over in allowing the packet to set anchor information - } + + // debug(1,"Connection %d: AP2 Control Packet received.", conn->connection_number); + + if (nread >= 28) { // must have at least 28 bytes for the timing information + if ((time_since_start < 2000000) && ((packet[0] & 0x10) == 0)) { + debug(1, + "Dropping what looks like a (non-sentinel) packet left over from a previous session " + "at %f ms.", + 0.000001 * time_since_start); } else { - debug(2, "Connection %d: AP2 Control Receiver -- error %d receiving a packet.", conn->connection_number, errno); + packet_number++; + // debug(1,"AP2 Packet %" PRIu64 ".", packet_number); + + if (packet_number == 1) { + if ((packet[0] & 0x10) != 0) { + debug(2, "First packet is a sentinel packet."); + } else { + debug(2, "First packet is a not a sentinel packet!"); + } + } + // debug(1,"rtp_ap2_control_receiver coded: %u, %u", packet[0], packet[1]); + // you might want to set this higher to specify how many initial timings to ignore + if (packet_number >= 1) { + if ((config.diagnostic_drop_packet_fraction == 0.0) || + (drand48() > config.diagnostic_drop_packet_fraction)) { + // store the from_sock_addr if we haven't already done so + // v remember to zero this when you're finished! + if (conn->ap2_remote_control_socket_addr_length == 0) { + memcpy(&conn->ap2_remote_control_socket_addr, &from_sock_addr, from_sock_addr_length); + conn->ap2_remote_control_socket_addr_length = from_sock_addr_length; + } + switch (packet[1]) { + case 215: // code 215, effectively an anchoring announcement + { + // struct timespec tnr; + // clock_gettime(CLOCK_REALTIME, &tnr); + // uint64_t local_realtime_now = timespec_to_ns(&tnr); + + /* + char obf[4096]; + char *obfp = obf; + int obfc; + for (obfc=0;obfcinput_rate); + // the actual latency is the notified latency plus the fixed latency + the added latency + + int32_t net_latency = + notified_latency + 11035 + + added_latency; // this is the latency between incoming frames and the DAC + net_latency = net_latency - + (int32_t)(config.audio_backend_buffer_desired_length * conn->input_rate); + // debug(1, "Net latency is %d frames.", net_latency); + + if (net_latency <= 0) { + if (conn->latency_warning_issued == 0) { + warn("The stream latency (%f seconds) it too short to accommodate an offset of %f " + "seconds and a backend buffer of %f seconds.", + ((notified_latency + 11035) * 1.0) / conn->input_rate, + config.audio_backend_latency_offset, + config.audio_backend_buffer_desired_length); + warn("(FYI the stream latency needed would be %f seconds.)", + config.audio_backend_buffer_desired_length - + config.audio_backend_latency_offset); + conn->latency_warning_issued = 1; + } + conn->latency = notified_latency + 11035; + } else { + conn->latency = notified_latency + 11035 + added_latency; + } + + set_ptp_anchor_info(conn, clock_id, frame_1 - 11035 - added_latency, + remote_packet_time_ns); + if (conn->anchor_clock != clock_id) { + debug(2, "Connection %d: Change Anchor Clock: %" PRIx64 ".", conn->connection_number, + clock_id); + } + + } break; + case 0xd6: + // six bytes in is the sequence number at the start of the encrypted audio packet + // returns the sequence number but we're not really interested + decipher_player_put_packet(packet + 6, nread - 6, conn); + break; + default: { + char *packet_in_hex_cstring = + debug_malloc_hex_cstring(packet, nread); // remember to free this afterwards + debug( + 1, + "AP2 Control Receiver Packet of first byte 0x%02X, type 0x%02X length %d received: " + "\"%s\".", + packet[0], packet[1], nread, packet_in_hex_cstring); + free(packet_in_hex_cstring); + } break; + } + } else { + debug(1, "AP2 Control Receiver -- dropping a packet."); + } + } } } else { - debug(2, "Connection %d: AP2 Control Receiver -- malformed packet, %d bytes long.", conn->connection_number, nread); + if (nread == -1) { + if ((errno == EAGAIN) || (errno == EWOULDBLOCK)) { + if (conn->airplay_stream_type == realtime_stream) { + debug(1, "Connection %d: no control packets for the last 7 seconds -- resetting anchor info", conn->connection_number); + reset_ptp_anchor_info(conn); + packet_number = 0; // start over in allowing the packet to set anchor information + } + } else { + debug(2, "Connection %d: AP2 Control Receiver -- error %d receiving a packet.", conn->connection_number, errno); + } + } else { + debug(2, "Connection %d: AP2 Control Receiver -- malformed packet, %d bytes long.", conn->connection_number, nread); + } } } } @@ -2927,7 +2925,7 @@ int have_timestamp_timing_information(rtsp_conn_info *conn) { if (conn->timing_type == ts_ptp) return have_ptp_timing_information(conn); else - return have_ntp_timestamp_timing_information(conn); + return have_ntp_timing_information(conn); } #else @@ -2943,6 +2941,6 @@ int local_time_to_frame(uint64_t time, uint32_t *frame, rtsp_conn_info *conn) { void reset_anchor_info(rtsp_conn_info *conn) { reset_ntp_anchor_info(conn); } int have_timestamp_timing_information(rtsp_conn_info *conn) { - return have_ntp_timestamp_timing_information(conn); + return have_ntp_timing_information(conn); } #endif diff --git a/rtsp.c b/rtsp.c index 09bd4d58..8cc36beb 100644 --- a/rtsp.c +++ b/rtsp.c @@ -96,7 +96,6 @@ #include "dbus-service.h" #endif - #include "mdns.h" // mDNS advertisement strings @@ -502,14 +501,9 @@ int pc_queue_get_item(pc_queue *the_queue, void *the_stuff) { #endif -void lock_player() { - debug_mutex_lock(&playing_conn_lock, 1000000, 3); -} - -void unlock_player() { - debug_mutex_unlock(&playing_conn_lock, 3); -} +void lock_player() { debug_mutex_lock(&playing_conn_lock, 1000000, 3); } +void unlock_player() { debug_mutex_unlock(&playing_conn_lock, 3); } int have_play_lock(rtsp_conn_info *conn) { int response = 0; @@ -552,12 +546,11 @@ void release_play_lock(rtsp_conn_info *conn) { debug(2, "Connection %d: play lock released.", conn->connection_number); else debug(2, "Play lock released."); - playing_conn = NULL; // let it go + playing_conn = NULL; // let it go } unlock_player(); } - // make conn the playing_conn, and kill the current session if permitted int get_play_lock(rtsp_conn_info *conn, int allow_session_interruption) { if (conn != NULL) @@ -630,7 +623,7 @@ int get_play_lock(rtsp_conn_info *conn, int allow_session_interruption) { if (conn != NULL) debug(2, "Connection %d: Got player lock.", conn->connection_number); else - debug(2, "Player released."); + debug(2, "Player released."); response = 0; } return response; @@ -1220,7 +1213,18 @@ static ssize_t write_encrypted(rtsp_conn_info *conn, const void *buf, size_t cou */ #endif -ssize_t read_from_rtsp_connection(rtsp_conn_info *conn, void *buf, size_t count) { +ssize_t timed_read_from_rtsp_connection(rtsp_conn_info *conn, uint64_t wait_time, void *buf, + size_t count) { + struct timeval tv; + tv.tv_sec = wait_time / 1000000000; // seconds + tv.tv_usec = (wait_time % 1000000000) / 1000; // microseconds + if (setsockopt(conn->fd, SOL_SOCKET, SO_RCVTIMEO, (const char *)&tv, sizeof tv) != 0) { + char errorstring[1024]; + strerror_r(errno, (char *)errorstring, sizeof(errorstring)); + debug(1, "could not set time limit on timed_read_from_rtsp_connection -- error %d \"%s\".", + errno, errorstring); + } + #ifdef CONFIG_AIRPLAY_2 if (conn->ap2_pairing_context.control_cipher_bundle.cipher_ctx) { conn->ap2_pairing_context.control_cipher_bundle.is_encrypted = 1; @@ -1233,6 +1237,34 @@ ssize_t read_from_rtsp_connection(rtsp_conn_info *conn, void *buf, size_t count) #endif } +ssize_t read_from_rtsp_connection(rtsp_conn_info *conn, void *buf, size_t count) { + // first try to read with a timeout, to see if there is any traffic... + ssize_t response = timed_read_from_rtsp_connection(conn, 4000000000L, buf, count); + if ((response == -1) && ((errno == EAGAIN) || (errno == EWOULDBLOCK))) { + if (conn->rtsp_link_is_idle == 0) { + conn->rtsp_link_is_idle = 1; +#ifdef CONFIG_AIRPLAY_2 + conn->last_anchor_info_is_valid = 0; +#endif + conn->anchor_remote_info_is_valid = 0; + conn->udp_clock_sender_is_initialised = 0; + conn->udp_clock_is_initialised = 0; + debug(1, "Connection %d: RTSP connection is idle.", conn->connection_number); + } + response = timed_read_from_rtsp_connection(conn, 0, buf, count); + } + if (conn->rtsp_link_is_idle == 1) { + conn->local_to_remote_time_difference_measurement_time = 0; + conn->local_to_remote_time_difference = 0; + conn->rtsp_link_is_idle = 0; + conn->first_packet_timestamp = 0; + conn->input_frame_rate_starting_point_is_valid = 0; + ab_resync(conn); + debug(1, "Connection %d: RTSP connection traffic has resumed.", conn->connection_number); + } + return response; +} + enum rtsp_read_request_response rtsp_read_request(rtsp_conn_info *conn, rtsp_message **the_packet) { *the_packet = NULL; // need this for error handling @@ -1418,6 +1450,7 @@ int msg_write_response(rtsp_conn_info *conn, rtsp_message *resp) { {403, "Unauthorized"}, {404, "Not Found"}, {451, "Unavailable"}, + {456, "Header Field Not Valid for Resource"}, {500, "Internal Server Error"}, {501, "Not Implemented"}}; // 451 is really "Unavailable For Legal Reasons"! @@ -1482,7 +1515,8 @@ int msg_write_response(rtsp_conn_info *conn, rtsp_message *resp) { #ifdef CONFIG_AIRPLAY_2 ssize_t reply; if (conn->ap2_pairing_context.control_cipher_bundle.is_encrypted) { - reply = write_encrypted(conn->fd, &conn->ap2_pairing_context.control_cipher_bundle, pkt, p - pkt); + reply = + write_encrypted(conn->fd, &conn->ap2_pairing_context.control_cipher_bundle, pkt, p - pkt); } else { reply = write(conn->fd, pkt, p - pkt); } @@ -1909,7 +1943,8 @@ void handle_setrateanchori(rtsp_conn_info *conn, rtsp_message *req, rtsp_message pthread_cleanup_push(mutex_unlock, &conn->flush_mutex); conn->ap2_rate = rate; if ((rate & 1) != 0) { - debug(2, "Connection %d: Start playing, with anchor clock %" PRIx64 ".", conn->connection_number, conn->networkTimeTimelineID); + debug(2, "Connection %d: Start playing, with anchor clock %" PRIx64 ".", + conn->connection_number, conn->networkTimeTimelineID); activity_monitor_signify_activity(1); conn->ap2_play_enabled = 1; } else { @@ -2313,6 +2348,9 @@ void handle_configure(rtsp_conn_info *conn __attribute__((unused)), void handle_feedback(rtsp_conn_info *conn, __attribute__((unused)) rtsp_message *req, __attribute__((unused)) rtsp_message *resp) { + debug(2, "Connection %d: POST %s Content-Length %d", conn->connection_number, req->path, + req->contentlength); + debug_log_rtsp_message(2, NULL, req); if (conn->airplay_stream_category == remote_control_stream) { plist_t array_plist = plist_new_array(); @@ -2349,7 +2387,9 @@ void handle_feedback(rtsp_conn_info *conn, __attribute__((unused)) rtsp_message void handle_command(__attribute__((unused)) rtsp_conn_info *conn, rtsp_message *req, __attribute__((unused)) rtsp_message *resp) { - debug_log_rtsp_message(3, "POST /command", req); + debug(2, "Connection %d: POST %s Content-Length %d", conn->connection_number, req->path, + req->contentlength); + debug_log_rtsp_message(2, NULL, req); if (rtsp_message_contains_plist(req)) { plist_t command_dict = NULL; plist_from_memory(req->content, req->contentlength, &command_dict); @@ -2468,12 +2508,11 @@ void handle_setpeers(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp char timing_list_message[4096]; timing_list_message[0] = 'T'; timing_list_message[1] = 0; - + // ensure the client itself is first -- it's okay if it's duplicated later - strncat(timing_list_message, " ", - sizeof(timing_list_message) - 1 - strlen(timing_list_message)); + strncat(timing_list_message, " ", sizeof(timing_list_message) - 1 - strlen(timing_list_message)); strncat(timing_list_message, (const char *)&conn->client_ip_string, - sizeof(timing_list_message) - 1 - strlen(timing_list_message)); + sizeof(timing_list_message) - 1 - strlen(timing_list_message)); plist_t addresses_array = NULL; plist_from_memory(req->content, req->contentlength, &addresses_array); @@ -2542,32 +2581,36 @@ void teardown_phase_two(rtsp_conn_info *conn) { // we are being asked to disconnect // this can be called more than once on the same connection -- // by the player itself but also by the play seesion being killed - debug(2, "Connection %d: TEARDOWN a %s connection.", conn->connection_number, - get_category_string(conn->airplay_stream_category)); + debug(2, "Connection %d: TEARDOWN %s connection.", conn->connection_number, + get_category_string(conn->airplay_stream_category)); if (conn->airplay_stream_category == remote_control_stream) { if (conn->rtp_data_thread) { - debug(2, "Connection %d (RC): TEARDOWN Delete Data Thread.", conn->connection_number); + debug(2, "Connection %d: TEARDOWN %s Delete Data Thread.", conn->connection_number, + get_category_string(conn->airplay_stream_category)); pthread_cancel(*conn->rtp_data_thread); pthread_join(*conn->rtp_data_thread, NULL); free(conn->rtp_data_thread); conn->rtp_data_thread = NULL; } - debug(2, "Connection %d: TEARDOWN Close Data Socket.", conn->connection_number); if (conn->data_socket) { + debug(2, "Connection %d: TEARDOWN %s Close Data Socket.", conn->connection_number, + get_category_string(conn->airplay_stream_category)); close(conn->data_socket); conn->data_socket = 0; } } if (conn->rtp_event_thread) { - debug(2, "Connection %d: TEARDOWN Delete Event Thread.", conn->connection_number); + debug(2, "Connection %d: TEARDOWN %s Delete Event Thread.", conn->connection_number, + get_category_string(conn->airplay_stream_category)); pthread_cancel(*conn->rtp_event_thread); pthread_join(*conn->rtp_event_thread, NULL); free(conn->rtp_event_thread); conn->rtp_event_thread = NULL; } - debug(2, "Connection %d: TEARDOWN Close Event Socket.", conn->connection_number); if (conn->event_socket) { + debug(2, "Connection %d: TEARDOWN %s Close Event Socket.", conn->connection_number, + get_category_string(conn->airplay_stream_category)); close(conn->event_socket); conn->event_socket = 0; } @@ -2611,16 +2654,20 @@ void handle_teardown_2(rtsp_conn_info *conn, __attribute__((unused)) rtsp_messag plist_t streams = plist_dict_get_item(messagePlist, "streams"); if (streams) { - debug(2, "Connection %d: TEARDOWN a %s.", conn->connection_number, + debug(2, "Connection %d: TEARDOWN %s Close the stream.", conn->connection_number, get_category_string(conn->airplay_stream_category)); // we are being asked to close a stream teardown_phase_one(conn); plist_free(streams); - debug(2, "Connection %d: TEARDOWN phase one complete", conn->connection_number); + debug(2, "Connection %d: TEARDOWN %s Close the stream complete", conn->connection_number, + get_category_string(conn->airplay_stream_category)); } else { + debug(2, "Connection %d: TEARDOWN %s Close the connection.", conn->connection_number, + get_category_string(conn->airplay_stream_category)); teardown_phase_one(conn); // try to do phase one anyway teardown_phase_two(conn); - debug(2, "Connection %d: TEARDOWN phase two complete", conn->connection_number); + debug(2, "Connection %d: TEARDOWN %s Close the connection complete", conn->connection_number, + get_category_string(conn->airplay_stream_category)); } //} else { // warn("Connection %d TEARDOWN received without having the player (no ANNOUNCE?)", @@ -2672,7 +2719,6 @@ void handle_teardown(rtsp_conn_info *conn, __attribute__((unused)) rtsp_message } void handle_flush(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) { - // TODO -- don't know what this is for in AP2 debug_log_rtsp_message(2, "FLUSH request", req); debug(3, "Connection %d: FLUSH", conn->connection_number); char *p = NULL; @@ -2698,11 +2744,7 @@ void handle_flush(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) { send_metadata('ssnc', 'flsr', NULL, 0, NULL, 0); #endif -// hack -- ignore it for airplay 2 -#ifdef CONFIG_AIRPLAY_2 - if (conn->airplay_type != ap_2) -#endif - player_flush(rtptime, conn); // will not crash even it there is no player thread. + player_flush(rtptime, conn); // will not crash even it there is no player thread. resp->respcode = 200; } else { @@ -2839,10 +2881,9 @@ void handle_setup_2(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) // ensure the client itself is first -- it's okay if it's duplicated later strncat(timing_list_message, " ", - sizeof(timing_list_message) - 1 - strlen(timing_list_message)); + sizeof(timing_list_message) - 1 - strlen(timing_list_message)); strncat(timing_list_message, (const char *)&conn->client_ip_string, - sizeof(timing_list_message) - 1 - strlen(timing_list_message)); - + sizeof(timing_list_message) - 1 - strlen(timing_list_message)); plist_t timing_peer_info = plist_dict_get_item(messagePlist, "timingPeerInfo"); if (timing_peer_info) { @@ -2988,7 +3029,11 @@ void handle_setup_2(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) debug(2, "Connection %d SETUP (RC): TCP Remote Control event port opened: %u.", conn->connection_number, conn->local_event_port); if (conn->rtp_event_thread != NULL) - debug(1, "previous rtp_event_thread allocation not freed, it seems."); + debug(1, + "Connection %d SETUP (RC): previous rtp_event_thread allocation not freed, it " + "seems.", + conn->connection_number); + conn->rtp_event_thread = malloc(sizeof(pthread_t)); if (conn->rtp_event_thread == NULL) die("Couldn't allocate space for pthread_t"); @@ -3209,8 +3254,10 @@ void handle_setup_2(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) plist_dict_set_item(setupResponsePlist, "streams", streams_array); resp->respcode = 200; } else if (conn->airplay_stream_category == remote_control_stream) { - debug(2, "Connection %d (RC): SETUP: Remote Control Stream received.", conn->connection_number); - + debug(2, "Connection %d (RC): SETUP: Remote Control Stream received from %s.", + conn->connection_number, conn->client_ip_string); + debug_log_rtsp_message(2, "Remote Control Stream SETUP incoming message", req); + /* // get a port to use as an data port // bind a new TCP port and get a socket conn->local_data_port = 0; // any port @@ -3226,10 +3273,9 @@ void handle_setup_2(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) debug(1, "Connection %d SETUP (RC): TCP Remote Control data port opened: %u.", conn->connection_number, conn->local_data_port); if (conn->rtp_data_thread != NULL) - debug(1, "previous rtp_data_thread allocation not freed, it seems."); - conn->rtp_data_thread = malloc(sizeof(pthread_t)); - if (conn->rtp_data_thread == NULL) - die("Couldn't allocate space for pthread_t"); + debug(1, "Connection %d SETUP (RC): previous rtp_data_thread allocation not freed, it + seems.", conn->connection_number); conn->rtp_data_thread = malloc(sizeof(pthread_t)); if + (conn->rtp_data_thread == NULL) die("Couldn't allocate space for pthread_t"); pthread_create(conn->rtp_data_thread, NULL, &rtp_data_receiver, (void *)conn); @@ -3241,6 +3287,7 @@ void handle_setup_2(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) plist_t coreResponseArray = plist_new_array(); plist_array_append_item(coreResponseArray, coreResponseDict); plist_dict_set_item(setupResponsePlist, "streams", coreResponseArray); + */ resp->respcode = 200; } else { debug(1, "Connection %d: SETUP: Stream received but no airplay category set. Nothing done.", @@ -3430,7 +3477,7 @@ void handle_set_parameter_parameter(rtsp_conn_info *conn, rtsp_message *req, if (dbus_service_is_running()) { shairport_sync_set_volume(shairportSyncSkeleton, config.airplay_volume); } -#endif +#endif } else if (strncmp(cp, "progress: ", strlen("progress: ")) == 0) { // this can be sent even when metadata is not solicited @@ -4171,7 +4218,7 @@ static void handle_get_parameter(__attribute__((unused)) rtsp_conn_info *conn, r if ((req->content) && (req->contentlength == strlen("volume\r\n")) && strstr(req->content, "volume") == req->content) { - debug(1, "Connection %d: Current volume (%.6f) requested", conn->connection_number, + debug(2, "Connection %d: Current volume (%.6f) requested", conn->connection_number, config.airplay_volume); char *p = malloc(128); // will be automatically deallocated with the response is deleted if (p) { @@ -4401,11 +4448,13 @@ static void handle_announce(rtsp_conn_info *conn, rtsp_message *req, rtsp_messag if ((paesiv == NULL) && (prsaaeskey == NULL)) { // debug(1,"Unencrypted session requested?"); conn->stream.encrypted = 0; - } else { + } else if ((paesiv != NULL) && (prsaaeskey != NULL)){ conn->stream.encrypted = 1; // debug(1,"Encrypted session requested"); + } else { + warn("Invalid Announce message -- missing paesiv or prsaaeskey."); + goto out; } - if (conn->stream.encrypted) { int len, keylen; uint8_t *aesiv = base64_dec(paesiv, &len); diff --git a/shairport.c b/shairport.c index 40c821f2..9d1657f0 100644 --- a/shairport.c +++ b/shairport.c @@ -159,7 +159,7 @@ int has_fltp_capable_aac_decoder(void) { const enum AVSampleFormat *p = codec->sample_fmts; if (p != NULL) { while ((has_capability == 0) && (*p != AV_SAMPLE_FMT_NONE)) { - if (*p == AV_SAMPLE_FMT_FLTP) + if (*p == AV_SAMPLE_FMT_FLTP) has_capability = 1; p++; } @@ -1379,7 +1379,7 @@ int parse_options(int argc, char **argv) { config.appName, temporary_airplay_id); // debug(1, "smi name: \"%s\"", shared_memory_interface_name); - config.nqptp_shared_memory_interface_name = strdup(shared_memory_interface_name); + config.nqptp_shared_memory_interface_name = strdup(NQPTP_INTERFACE_NAME); char apids[6 * 2 + 5 + 1]; // six pairs of digits, 5 colons and a NUL apids[6 * 2 + 5] = 0; // NUL termination @@ -1454,9 +1454,9 @@ int parse_options(int argc, char **argv) { // now, do the substitutions in the service name char hostname[100]; gethostname(hostname, 100); - + // strip off a terminating ., e.g. .local from the hostname - char *last_dot = strrchr(hostname,'.'); + char *last_dot = strrchr(hostname, '.'); if (last_dot != NULL) *last_dot = '\0'; @@ -1574,10 +1574,10 @@ void exit_function() { if (g_main_loop) { debug(2, "Stopping D-Bus Loop Thread"); g_main_loop_quit(g_main_loop); - - // If the request to exit has come from the D-Bus system, + + // If the request to exit has come from the D-Bus system, // the D-Bus Loop Thread will not exit until the request is completed - // so don't wait for it + // so don't wait for it if (type_of_exit_cleanup != TOE_dbus) pthread_join(dbus_thread, NULL); } @@ -2023,10 +2023,10 @@ int main(int argc, char **argv) { apfh = apfh >> 32; uint32_t apf32 = apf; uint32_t apfh32 = apfh; - debug(1, "startup in Airplay 2 mode with features 0x%" PRIx32 ",0x%" PRIx32 " on device \"%s\".", + debug(1, "startup in AirPlay 2 mode, with features 0x%" PRIx32 ",0x%" PRIx32 " on device \"%s\".", apf32, apfh32, config.airplay_device_id); #else - debug(1, "startup in Airplay 1 mode."); + debug(1, "startup in classic Airplay (aka \"AirPlay 1\") mode."); #endif // control-c (SIGINT) cleanly @@ -2180,8 +2180,9 @@ int main(int argc, char **argv) { debug(1, "mdns backend \"%s\".", strnull(config.mdns_name)); debug(2, "userSuppliedLatency is %d.", config.userSuppliedLatency); debug(1, "interpolation setting is \"%s\".", - config.packet_stuffing == ST_basic ? "basic" - : config.packet_stuffing == ST_soxr ? "soxr" : "auto"); + config.packet_stuffing == ST_basic ? "basic" + : config.packet_stuffing == ST_soxr ? "soxr" + : "auto"); debug(1, "interpolation soxr_delay_threshold is %d.", config.soxr_delay_threshold); debug(1, "resync time is %f seconds.", config.resyncthreshold); debug(1, "allow a session to be interrupted: %d.", config.allow_session_interruption); @@ -2338,7 +2339,8 @@ int main(int argc, char **argv) { ptp_send_control_message_string("T"); // get nqptp to create the named shm interface usleep(ptp_wait_interval_us); ptp_check_times++; - } while ((ptp_shm_interface_open() != 0) && (ptp_check_times < (10000000 / ptp_wait_interval_us))); + } while ((ptp_shm_interface_open() != 0) && + (ptp_check_times < (10000000 / ptp_wait_interval_us))); if (ptp_shm_interface_open() != 0) { die("Can't access NQPTP! Is it installed and running?");