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?");