nils/shairport-sync
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

partial move to using a nanosecond-based system timer. More to come.

Browse Source
This commit is contained in:
Mike Brady
2020-02-24 19:40:44 +00:00
parent 820ee1c9f2
commit 67e9b1b6cd
9 changed files with 145 additions and 167 deletions
Download Patch File Download Diff File Expand all files Collapse all files
activity_monitor.c
+7 -9
View File
@@ -196,21 +196,19 @@ void *activity_monitor_thread_code(void *arg) {
} else {
state = am_timing_out;
uint64_t time_to_wait_for_wakeup_fp =
(uint64_t)(config.active_state_timeout * 1000000); // resolution of microseconds
time_to_wait_for_wakeup_fp = time_to_wait_for_wakeup_fp << 32;
time_to_wait_for_wakeup_fp = time_to_wait_for_wakeup_fp / 1000000;
uint64_t time_to_wait_for_wakeup_ns = (uint64_t)(config.active_state_timeout * 1000000000);
#ifdef COMPILE_FOR_LINUX_AND_FREEBSD_AND_CYGWIN_AND_OPENBSD
uint64_t time_of_wakeup_fp = get_absolute_time_in_fp() + time_to_wait_for_wakeup_fp;
sec = time_of_wakeup_fp >> 32;
nsec = ((time_of_wakeup_fp & 0xffffffff) * 1000000000) >> 32;
uint64_t time_of_wakeup_ns = get_absolute_time_in_ns() + time_to_wait_for_wakeup_ns;
sec = time_of_wakeup_ns / 1000000000;
nsec = time_of_wakeup_ns % 1000000000;
time_for_wait.tv_sec = sec;
time_for_wait.tv_nsec = nsec;
#endif
#ifdef COMPILE_FOR_OSX
sec = time_to_wait_for_wakeup_fp >> 32;
nsec = ((time_to_wait_for_wakeup_fp & 0xffffffff) * 1000000000) >> 32;
sec = time_to_wait_for_wakeup_ns / 1000000000;
nsec = time_to_wait_for_wakeup_ns % 1000000000;
time_for_wait.tv_sec = sec;
time_for_wait.tv_nsec = nsec;
#endif
audio_alsa.c
+50 -60
View File
@@ -210,9 +210,6 @@ int precision_delay_available() {
generate_zero_frames(silence, frames_of_silence, config.output_format,
use_dither, // i.e. with dither
dither_random_number_store);
// debug(1,"Play %d frames of silence with most_recent_write_time of
// %" PRIx64 ".",
// frames_of_silence,most_recent_write_time);
do_play(silence, frames_of_silence);
pthread_cleanup_pop(1);
// now we can get the delay, and we'll note if it uses update timestamps
@@ -255,8 +252,6 @@ static uint64_t frames_played_at_measurement_start_time;
static uint64_t measurement_time;
static uint64_t frames_played_at_measurement_time;
volatile uint64_t most_recent_write_time;
static uint64_t frames_sent_for_playing;
static uint64_t frame_index;
static int measurement_data_is_valid;
@@ -1350,7 +1345,6 @@ static int init(int argc, char **argv) {
// length of the queue
// if the queue gets too short, stuff it with silence
most_recent_write_time = 0; // could be used by the alsa_buffer_monitor_thread_code
pthread_create(&alsa_buffer_monitor_thread, NULL, &alsa_buffer_monitor_thread_code, NULL);
return response;
@@ -1605,6 +1599,7 @@ int delay(long *the_delay) {
}
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) {
*elapsed_time = measurement_time - measurement_start_time;
@@ -1657,7 +1652,7 @@ int do_play(void *buf, int samples) {
if ((frame_index == start_measurement_from_this_frame) ||
((frame_index > start_measurement_from_this_frame) && (frame_index % 32 == 0))) {
measurement_time = get_absolute_time_in_fp();
measurement_time = get_absolute_time_in_ns();
frames_played_at_measurement_time = frames_sent_for_playing - my_delay - samples;
if (frame_index == start_measurement_from_this_frame) {
@@ -1744,6 +1739,7 @@ int do_close() {
// debug(1,"alsa: do_close() -- closing the output device");
if ((derr = snd_pcm_drop(alsa_handle)))
debug(1, "Error %d (\"%s\") dropping output device.", derr, snd_strerror(derr));
usleep(5000);
if ((derr = snd_pcm_hw_free(alsa_handle)))
debug(1, "Error %d (\"%s\") freeing the output device hardware.", derr, snd_strerror(derr));
@@ -1946,7 +1942,7 @@ void *alsa_buffer_monitor_thread_code(__attribute__((unused)) void *arg) {
alsa_device_init();
alsa_device_initialised = 1;
}
int sleep_time_ms = (int)(config.disable_standby_mode_silence_scan_interval * 1000);
int sleep_time_us = (int)(config.disable_standby_mode_silence_scan_interval * 1000000);
pthread_cleanup_debug_mutex_lock(&alsa_mutex, 200000, 0);
// check possible state transitions here
if ((alsa_backend_state == abm_disconnected) && (config.keep_dac_busy != 0)) {
@@ -1974,57 +1970,51 @@ void *alsa_buffer_monitor_thread_code(__attribute__((unused)) void *arg) {
int reply;
long buffer_size = 0;
snd_pcm_state_t state;
uint64_t present_time = get_absolute_time_in_fp();
if ((most_recent_write_time == 0) || (present_time > most_recent_write_time)) {
reply = delay_and_status(&state, &buffer_size, NULL);
if (reply != 0) {
buffer_size = 0;
char errorstring[1024];
strerror_r(-reply, (char *)errorstring, sizeof(errorstring));
debug(1, "alsa: alsa_buffer_monitor_thread_code delay error %d: \"%s\".", reply,
(char *)errorstring);
}
long buffer_size_threshold =
(long)(config.disable_standby_mode_silence_threshold * config.output_rate);
size_t size_of_silence_buffer;
if (buffer_size < buffer_size_threshold) {
uint64_t sleep_time_in_fp = sleep_time_ms;
sleep_time_in_fp = sleep_time_in_fp << 32;
sleep_time_in_fp = sleep_time_in_fp / 1000;
int frames_of_silence = 1024;
size_of_silence_buffer = frames_of_silence * frame_size;
void *silence = malloc(size_of_silence_buffer);
if (silence == NULL) {
warn("disable_standby_mode has been turned off because a memory allocation error "
"occurred.");
error_detected = 1;
} else {
int ret;
pthread_cleanup_push(malloc_cleanup, silence);
int use_dither = 0;
if ((alsa_mix_ctrl == NULL) && (config.ignore_volume_control == 0) &&
(config.airplay_volume != 0.0))
use_dither = 1;
dither_random_number_store =
generate_zero_frames(silence, frames_of_silence, config.output_format,
use_dither, // i.e. with dither
dither_random_number_store);
ret = do_play(silence, frames_of_silence);
frame_count++;
pthread_cleanup_pop(1); // free malloced buffer
if (ret < 0) {
error_count++;
char errorstring[1024];
strerror_r(-ret, (char *)errorstring, sizeof(errorstring));
debug(2, "alsa: alsa_buffer_monitor_thread_code error %d (\"%s\") writing %d samples "
"to alsa device -- %d errors in %d trials.",
ret, (char *)errorstring, frames_of_silence, error_count, frame_count);
if ((error_count > 40) && (frame_count < 100)) {
warn("disable_standby_mode has been turned off because too many underruns "
"occurred. Is Shairport Sync outputting to a virtual device or running in a "
"virtual machine?");
error_detected = 1;
}
reply = delay_and_status(&state, &buffer_size, NULL);
if (reply != 0) {
buffer_size = 0;
char errorstring[1024];
strerror_r(-reply, (char *)errorstring, sizeof(errorstring));
debug(1, "alsa: alsa_buffer_monitor_thread_code delay error %d: \"%s\".", reply,
(char *)errorstring);
}
long buffer_size_threshold =
(long)(config.disable_standby_mode_silence_threshold * config.output_rate);
size_t size_of_silence_buffer;
if (buffer_size < buffer_size_threshold) {
int frames_of_silence = 1024;
size_of_silence_buffer = frames_of_silence * frame_size;
void *silence = malloc(size_of_silence_buffer);
if (silence == NULL) {
warn("disable_standby_mode has been turned off because a memory allocation error "
"occurred.");
error_detected = 1;
} else {
int ret;
pthread_cleanup_push(malloc_cleanup, silence);
int use_dither = 0;
if ((alsa_mix_ctrl == NULL) && (config.ignore_volume_control == 0) &&
(config.airplay_volume != 0.0))
use_dither = 1;
dither_random_number_store =
generate_zero_frames(silence, frames_of_silence, config.output_format,
use_dither, // i.e. with dither
dither_random_number_store);
ret = do_play(silence, frames_of_silence);
frame_count++;
pthread_cleanup_pop(1); // free malloced buffer
if (ret < 0) {
error_count++;
char errorstring[1024];
strerror_r(-ret, (char *)errorstring, sizeof(errorstring));
debug(2, "alsa: alsa_buffer_monitor_thread_code error %d (\"%s\") writing %d samples "
"to alsa device -- %d errors in %d trials.",
ret, (char *)errorstring, frames_of_silence, error_count, frame_count);
if ((error_count > 40) && (frame_count < 100)) {
warn("disable_standby_mode has been turned off because too many underruns "
"occurred. Is Shairport Sync outputting to a virtual device or running in a "
"virtual machine?");
error_detected = 1;
}
}
}
@@ -2032,7 +2022,7 @@ void *alsa_buffer_monitor_thread_code(__attribute__((unused)) void *arg) {
}
debug_mutex_unlock(&alsa_mutex, 0);
pthread_cleanup_pop(0); // release the mutex
usleep(sleep_time_ms * 1000); // has a cancellation point in it
usleep(sleep_time_us); // has a cancellation point in it
}
pthread_exit(NULL);
}
audio_jack.c
+4 -4
View File
@@ -395,13 +395,13 @@ int jack_delay(long *the_delay) {
// occupancy after another transfer had occurred, so we could "lose" a full transfer
// (e.g. 1024 frames @ 44,100 fps ~ 23.2 milliseconds)
pthread_mutex_lock(&buffer_mutex);
int64_t time_now = get_absolute_time_in_fp();
int64_t delta = time_now - time_of_latest_transfer;
int64_t time_now = get_absolute_time_in_ns();
int64_t delta = time_now - time_of_latest_transfer; // nanoseconds
size_t audio_occupancy_now = jack_ringbuffer_read_space(jackbuf) / bytes_per_frame;
debug(2, "audio_occupancy_now is %d.", audio_occupancy_now);
pthread_mutex_unlock(&buffer_mutex);
int64_t frames_processed_since_latest_latency_check = (delta * sample_rate) >> 32;
int64_t frames_processed_since_latest_latency_check = (delta * sample_rate) / 1000000000;
// debug(1,"delta: %" PRId64 " frames.",frames_processed_since_latest_latency_check);
// jack_latency is set by the graph() callback, it's the average of the maximum
// latencies of all our output ports. Adjust this constant baseline delay according
@@ -456,7 +456,7 @@ int play(void *buf, int samples) {
}
#endif
}
time_of_latest_transfer = get_absolute_time_in_fp();
time_of_latest_transfer = get_absolute_time_in_ns();
pthread_mutex_unlock(&buffer_mutex);
if (samples) {
warn("JACK ringbuffer overrun. Dropped %d samples.", samples);
common.c
+35 -40
View File
@@ -89,9 +89,9 @@ void set_alsa_out_dev(char *);
config_t config_file_stuff;
pthread_t main_thread_id;
uint64_t fp_time_at_startup, fp_time_at_last_debug_message;
uint64_t ns_time_at_startup, ns_time_at_last_debug_message;
// always lock use this when accessing the fp_time_at_last_debug_message
// always lock use this when accessing the ns_time_at_last_debug_message
static pthread_mutex_t debug_timing_lock = PTHREAD_MUTEX_INITIALIZER;
pthread_mutex_t the_conn_lock = PTHREAD_MUTEX_INITIALIZER;
@@ -218,14 +218,13 @@ void _die(const char *filename, const int linenumber, const char *format, ...) {
char *s;
if (debuglev) {
pthread_mutex_lock(&debug_timing_lock);
uint64_t time_now = get_absolute_time_in_fp();
uint64_t time_since_start = time_now - fp_time_at_startup;
uint64_t time_since_last_debug_message = time_now - fp_time_at_last_debug_message;
fp_time_at_last_debug_message = time_now;
uint64_t time_now = get_absolute_time_in_ns();
uint64_t time_since_start = time_now - ns_time_at_startup;
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);
uint64_t divisor = (uint64_t)1 << 32;
s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / divisor,
1.0 * time_since_last_debug_message / divisor, filename,
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: ");
} else {
s = b;
@@ -247,14 +246,13 @@ void _warn(const char *filename, const int linenumber, const char *format, ...)
char *s;
if (debuglev) {
pthread_mutex_lock(&debug_timing_lock);
uint64_t time_now = get_absolute_time_in_fp();
uint64_t time_since_start = time_now - fp_time_at_startup;
uint64_t time_since_last_debug_message = time_now - fp_time_at_last_debug_message;
fp_time_at_last_debug_message = time_now;
uint64_t time_now = get_absolute_time_in_ns();
uint64_t time_since_start = time_now - ns_time_at_startup;
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);
uint64_t divisor = (uint64_t)1 << 32;
s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / divisor,
1.0 * time_since_last_debug_message / divisor, filename,
s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000,
1.0 * time_since_last_debug_message / 1000000000, filename,
linenumber, " *warning: ");
} else {
s = b;
@@ -275,14 +273,13 @@ void _debug(const char *filename, const int linenumber, int level, const char *f
char b[1024];
b[0] = 0;
pthread_mutex_lock(&debug_timing_lock);
uint64_t time_now = get_absolute_time_in_fp();
uint64_t time_since_start = time_now - fp_time_at_startup;
uint64_t time_since_last_debug_message = time_now - fp_time_at_last_debug_message;
fp_time_at_last_debug_message = time_now;
uint64_t time_now = get_absolute_time_in_ns();
uint64_t time_since_start = time_now - ns_time_at_startup;
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);
uint64_t divisor = (uint64_t)1 << 32;
char *s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / divisor,
1.0 * time_since_last_debug_message / divisor, filename,
char *s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000,
1.0 * time_since_last_debug_message / 1000000000, filename,
linenumber, " ");
va_list args;
va_start(args, format);
@@ -300,14 +297,13 @@ void _inform(const char *filename, const int linenumber, const char *format, ...
char *s;
if (debuglev) {
pthread_mutex_lock(&debug_timing_lock);
uint64_t time_now = get_absolute_time_in_fp();
uint64_t time_since_start = time_now - fp_time_at_startup;
uint64_t time_since_last_debug_message = time_now - fp_time_at_last_debug_message;
fp_time_at_last_debug_message = time_now;
uint64_t time_now = get_absolute_time_in_ns();
uint64_t time_since_start = time_now - ns_time_at_startup;
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);
uint64_t divisor = (uint64_t)1 << 32;
s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / divisor,
1.0 * time_since_last_debug_message / divisor, filename,
s = generate_preliminary_string(b, sizeof(b), 1.0 * time_since_start / 1000000000,
1.0 * time_since_last_debug_message / 1000000000, filename,
linenumber, " ");
} else {
s = b;
@@ -1133,7 +1129,9 @@ char *str_replace(const char *string, const char *substr, const char *replacemen
/* from http://burtleburtle.net/bob/rand/smallprng.html */
// this is not thread-safe, so we need a mutex on it to use it properly// always lock use this when accessing the fp_time_at_last_debug_message
// this is not thread-safe, so we need a mutex on it to use it properly.
// always lock use this when accessing the fp_time_at_last_debug_message
pthread_mutex_t r64_mutex = PTHREAD_MUTEX_INITIALIZER;
// typedef uint64_t u8;
@@ -1241,18 +1239,17 @@ int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
timeoutTime.tv_sec = time_then;
timeoutTime.tv_nsec = time_then_nsec;
int64_t start_time = get_absolute_time_in_fp();
int64_t start_time = get_absolute_time_in_ns();
int r = pthread_mutex_timedlock(mutex, &timeoutTime);
int64_t et = get_absolute_time_in_fp() - start_time;
int64_t et = get_absolute_time_in_ns() - start_time;
if ((debuglevel != 0) && (r != 0) && (debugmessage != NULL)) {
et = (et * 1000000) >> 32; // microseconds
char errstr[1000];
if (r == ETIMEDOUT)
debug(debuglevel,
"timed out waiting for a mutex, having waiting %f seconds, with a maximum "
"waiting time of %d microseconds. \"%s\".",
(1.0 * et) / 1000000, dally_time, debugmessage);
(1.0 * et) / 1000000000, dally_time, debugmessage);
else
debug(debuglevel, "error %d: \"%s\" waiting for a mutex: \"%s\".", r,
strerror_r(r, errstr, sizeof(errstr)), debugmessage);
@@ -1301,7 +1298,7 @@ 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);
uint64_t time_at_start = get_absolute_time_in_fp();
uint64_t time_at_start = get_absolute_time_in_ns();
char dstring[1000];
memset(dstring, 0, sizeof(dstring));
snprintf(dstring, sizeof(dstring), "%s:%d", filename, line);
@@ -1310,12 +1307,10 @@ int _debug_mutex_lock(pthread_mutex_t *mutex, useconds_t dally_time, const char
int result = sps_pthread_mutex_timedlock(mutex, dally_time, dstring, debuglevel);
if (result == ETIMEDOUT) {
result = pthread_mutex_lock(mutex);
uint64_t time_delay = get_absolute_time_in_fp() - time_at_start;
uint64_t divisor = (uint64_t)1 << 32;
double delay = 1.0 * time_delay / divisor;
uint64_t time_delay = get_absolute_time_in_ns() - time_at_start;
debug(debuglevel,
"mutex_lock \"%s\" at \"%s\" expected max wait: %0.9f, actual wait: %0.9f sec.",
mutexname, dstring, (1.0 * dally_time) / 1000000, delay);
mutexname, dstring, (1.0 * dally_time) / 1000000, 0.000000001 * time_delay);
}
pthread_setcancelstate(oldState, NULL);
return result;
common.h
+1 -1
View File
@@ -353,7 +353,7 @@ uint64_t get_absolute_time_in_fp(void);
uint64_t get_absolute_time_in_ns(void);
// time at startup for debugging timing
extern uint64_t fp_time_at_startup, fp_time_at_last_debug_message;
extern uint64_t ns_time_at_startup, ns_time_at_last_debug_message;
// this is for reading an unsigned 32 bit number, such as an RTP timestamp
dacp.c
+3 -4
View File
@@ -201,7 +201,7 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
// debug(1,"Error %d \"%s\" at getaddrinfo.",ires,gai_strerror(ires));
response.code = 498; // Bad Address information for the DACP server
} else {
uint64_t start_time = get_absolute_time_in_fp();
uint64_t start_time = get_absolute_time_in_ns();
pthread_cleanup_push(addrinfo_cleanup, (void *)&res);
// only do this one at a time -- not sure it is necessary, but better safe than sorry
@@ -352,10 +352,9 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
}
pthread_cleanup_pop(1); // this should free the addrinfo
// freeaddrinfo(res);
uint64_t et = get_absolute_time_in_fp() - start_time;
et = (et * 1000000) >> 32; // microseconds
uint64_t et = get_absolute_time_in_ns() - start_time; // this will be in nanoseconds
debug(3, "dacp_send_command: %f seconds, response code %d, command \"%s\".",
(1.0 * et) / 1000000, response.code, command);
(1.0 * et) / 1000000000, response.code, command);
}
*body = response.body;
*bodysize = response.size;
player.c
+33 -37
View File
@@ -124,7 +124,7 @@ static void ab_resync(rtsp_conn_info *conn) {
conn->audio_buffer[i].ready = 0;
conn->audio_buffer[i].resend_request_number = 0;
conn->audio_buffer[i].resend_time = 0; // this is either zero or the time the last resend was requested.
conn->audio_buffer[i].initialisation_time = 0; // this is either the time the packet was received or the time it was noticed the packet was missing.
conn->audio_buffer[i].initialisation_time = 0; // this is either the time the packet was received or the time it was noticed the packet was missing.
conn->audio_buffer[i].sequence_number = 0;
}
conn->ab_synced = 0;
@@ -564,7 +564,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
int rc = pthread_cond_signal(&conn->flowcontrol);
if (rc)
debug(1, "Error signalling flowcontrol.");
// resend checks
{
uint64_t minimum_wait_time = (uint64_t)(config.resend_control_first_check_time * (uint64_t)0x100000000);
@@ -572,7 +572,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
uint64_t minimum_remaining_time = (uint64_t)((config.resend_control_last_check_time + config.audio_backend_buffer_desired_length)* (uint64_t)0x100000000);
uint64_t latency_time = (uint64_t)(conn->latency * (uint64_t)0x100000000);
latency_time = latency_time / (uint64_t)conn->input_rate;
int x; // this is the first frame to be checked
// if we detected a first empty frame before and if it's still in the buffer!
if ((first_possibly_missing_frame >= 0) && (position_in_modulo_uint16_t_buffer(first_possibly_missing_frame, conn->ab_read, conn->ab_write, NULL))) {
@@ -580,9 +580,9 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
} else {
x = conn->ab_read;
}
first_possibly_missing_frame = -1; // has not been set
int missing_frame_run_count = 0;
int start_of_missing_frame_run = -1;
int number_of_missing_frames = 0;
@@ -604,12 +604,12 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
if (too_early)
check_buf->status |= 1<<3; // too early
else
check_buf->status &= 0xFF-(1<<3); // not too early
check_buf->status &= 0xFF-(1<<3); // not too early
if (too_soon_after_last_request)
check_buf->status |= 1<<4; // too soon after last request
else
check_buf->status &= 0xFF-(1<<4); // not too soon after last request
if ((!too_soon_after_last_request) && (!too_late) && (!too_early)){
if (start_of_missing_frame_run == -1) {
start_of_missing_frame_run = x;
@@ -619,7 +619,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
}
check_buf->resend_time = time_now; // setting the time to now because we are definitely going to take action
check_buf->resend_request_number++;
debug(3,"Frame %d is missing with ab_read of %u and ab_write of %u.", x, conn->ab_read, conn->ab_write);
debug(3,"Frame %d is missing with ab_read of %u and ab_write of %u.", x, conn->ab_read, conn->ab_write);
}
// if (too_late) {
// debug(1,"too late to get missing frame %u.", x);
@@ -631,13 +631,13 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, uint8_t *data, in
if (((check_buf->ready) || (x == conn->ab_write)) && (missing_frame_run_count > 0)) {
// send a resend request
if (missing_frame_run_count > 1)
debug(2,"request resend of %d packets starting at seqno %u.", missing_frame_run_count, start_of_missing_frame_run);
debug(2,"request resend of %d packets starting at seqno %u.", missing_frame_run_count, start_of_missing_frame_run);
if (config.disable_resend_requests == 0) {
debug_mutex_unlock(&conn->ab_mutex, 3);
rtp_request_resend(start_of_missing_frame_run, missing_frame_run_count, conn);
debug_mutex_lock(&conn->ab_mutex, 20000, 1);
conn->resend_requests++;
}
}
start_of_missing_frame_run = -1;
missing_frame_run_count = 0;
}
@@ -1454,7 +1454,7 @@ static int stuff_buffer_basic_32(int32_t *inptr, int length, sps_format_t l_outp
int32_t stat_n = 0;
double stat_mean = 0.0;
double stat_M2 = 0.0;
double longest_soxr_execution_time_us = 0.0;
double longest_soxr_execution_time = 0.0;
int64_t packets_processed = 0;
int stuff_buffer_soxr_32(int32_t *inptr, int32_t *scratchBuffer, int length,
@@ -1482,7 +1482,7 @@ int stuff_buffer_soxr_32(int32_t *inptr, int32_t *scratchBuffer, int length,
size_t odone;
uint64_t soxr_start_time = get_absolute_time_in_fp();
uint64_t soxr_start_time = get_absolute_time_in_ns();
soxr_error_t error = soxr_oneshot(length, length + tstuff, 2, // Rates and # of chans.
inptr, length, NULL, // Input.
@@ -1499,15 +1499,15 @@ int stuff_buffer_soxr_32(int32_t *inptr, int32_t *scratchBuffer, int length,
// mean and variance calculations from "online_variance" algorithm at
// https://en.wikipedia.org/wiki/Algorithms_for_calculating_variance#Online_algorithm
double soxr_execution_time_us =
(((get_absolute_time_in_fp() - soxr_start_time) * 1000000) >> 32) * 1.0;
double soxr_execution_time =
(get_absolute_time_in_ns() - soxr_start_time) * 0.000000001;
// debug(1,"soxr_execution_time_us: %10.1f",soxr_execution_time_us);
if (soxr_execution_time_us > longest_soxr_execution_time_us)
longest_soxr_execution_time_us = soxr_execution_time_us;
if (soxr_execution_time > longest_soxr_execution_time)
longest_soxr_execution_time = soxr_execution_time;
stat_n += 1;
double stat_delta = soxr_execution_time_us - stat_mean;
double stat_delta = soxr_execution_time - stat_mean;
stat_mean += stat_delta / stat_n;
stat_M2 += stat_delta * (soxr_execution_time_us - stat_mean);
stat_M2 += stat_delta * (soxr_execution_time - stat_mean);
int i;
int32_t *ip, *op;
@@ -1553,15 +1553,15 @@ int stuff_buffer_soxr_32(int32_t *inptr, int32_t *scratchBuffer, int length,
}
if (packets_processed % 1250 == 0) {
debug(3, "soxr_oneshot execution time in microseconds: mean, standard deviation and max "
debug(3, "soxr_oneshot execution time in nanoseconds: mean, standard deviation and max "
"for %" PRId32 " interpolations in the last "
"1250 packets. %10.1f, %10.1f, %10.1f.",
"1250 packets. %10.6f, %10.6f, %10.6f.",
stat_n, stat_mean, stat_n <= 1 ? 0.0 : sqrtf(stat_M2 / (stat_n - 1)),
longest_soxr_execution_time_us);
longest_soxr_execution_time);
stat_n = 0;
stat_mean = 0.0;
stat_M2 = 0.0;
longest_soxr_execution_time_us = 0.0;
longest_soxr_execution_time = 0.0;
}
conn->amountStuffed = tstuff;
@@ -2365,11 +2365,11 @@ void *player_thread_func(void *arg) {
amount_to_stuff = 0; // no stuffing if it's been disabled
// Apply DSP here
// check the state of loudness and convolution flags here and don't change them for the frame
int do_loudness = config.loudness;
#ifdef CONFIG_CONVOLUTION
int do_convolution = 0;
@@ -2377,12 +2377,12 @@ void *player_thread_func(void *arg) {
do_convolution = 1;
// we will apply the convolution gain if convolution is enabled, even if there is no valid convolution happening
int convolution_is_enabled = 0;
if (config.convolution)
convolution_is_enabled = 1;
#endif
if (do_loudness
#ifdef CONFIG_CONVOLUTION
|| convolution_is_enabled
@@ -2533,7 +2533,7 @@ void *player_thread_func(void *arg) {
// update the watchdog
if ((config.dont_check_timeout == 0) && (config.timeout != 0)) {
uint64_t time_now = get_absolute_time_in_fp();
uint64_t time_now = get_absolute_time_in_ns();
debug_mutex_lock(&conn->watchdog_mutex, 1000, 0);
conn->watchdog_bark_time = time_now;
debug_mutex_unlock(&conn->watchdog_mutex, 0);
@@ -2620,12 +2620,8 @@ void *player_thread_func(void *arg) {
conn->frame_rate_status = 0;
if (conn->frame_rate_status) {
conn->frame_rate =
(1.0 * frames_played) /
(1000000000.0 * frames_played) /
elapsed_play_time; // an IEEE double calculation with two 64-bit integers
conn->frame_rate =
conn->frame_rate * (uint64_t)0x100000000; // this should just change the [binary]
// exponent in the IEEE FP representation;
// the mantissa should be unaffected.
} else {
conn->frame_rate = 0.0;
}
@@ -2758,7 +2754,7 @@ void player_volume_without_notification(double airplay_volume, rtsp_conn_info *c
int32_t hw_max_db = 0, hw_min_db = 0; // zeroed to quieten an incorrect uninitialised warning
int32_t sw_max_db = 0, sw_min_db = -9630;
if (config.output->parameters) {
volume_mode = vol_hw_only;
audio_parameters audio_information;
@@ -2928,7 +2924,7 @@ void player_volume_without_notification(double airplay_volume, rtsp_conn_info *c
if (config.logOutputLevel) {
inform("Output Level set to: %.2f dB.", scaled_attenuation / 100.0);
}
#ifdef CONFIG_METADATA
// here, send the 'pvol' metadata message when the airplay volume information
// is being used by shairport sync to control the output volume
@@ -2938,7 +2934,7 @@ void player_volume_without_notification(double airplay_volume, rtsp_conn_info *c
if (volume_mode == vol_both) {
// normalise the maximum output to the hardware device's max output
snprintf(dv, 127, "%.2f,%.2f,%.2f,%.2f", airplay_volume, (scaled_attenuation - max_db + hw_max_db) / 100.0,
(min_db - max_db + hw_max_db) / 100.0, (max_db - max_db + hw_max_db) / 100.0);
(min_db - max_db + hw_max_db) / 100.0, (max_db - max_db + hw_max_db) / 100.0);
} else {
snprintf(dv, 127, "%.2f,%.2f,%.2f,%.2f", airplay_volume, scaled_attenuation / 100.0,
min_db / 100.0, max_db / 100.0);
@@ -2972,7 +2968,7 @@ void player_volume_without_notification(double airplay_volume, rtsp_conn_info *c
}
#endif
// here, store the volume for possible use in the future
config.airplay_volume = airplay_volume;
debug_mutex_unlock(&conn->volume_control_mutex, 3);
rtsp.c
+4 -4
View File
@@ -286,7 +286,7 @@ void *player_watchdog_thread_code(void *arg) {
uint64_t last_watchdog_bark_time = conn->watchdog_bark_time;
debug_mutex_unlock(&conn->watchdog_mutex, 0);
if (last_watchdog_bark_time != 0) {
uint64_t time_since_last_bark = (get_absolute_time_in_fp() - last_watchdog_bark_time) >> 32;
uint64_t time_since_last_bark = (get_absolute_time_in_ns() - last_watchdog_bark_time) / 1000000000;
uint64_t ct = config.timeout; // go from int to 64-bit int
if (time_since_last_bark >= ct) {
@@ -666,7 +666,7 @@ enum rtsp_read_request_response rtsp_read_request(rtsp_conn_info *conn, rtsp_mes
}
uint64_t threshold_time =
get_absolute_time_in_fp() + ((uint64_t)15 << 32); // i.e. fifteen seconds from now
get_absolute_time_in_ns() + ((uint64_t)15000000000); // i.e. fifteen seconds from now
int warning_message_sent = 0;
const size_t max_read_chunk = 1024 * 1024 / 16;
@@ -679,7 +679,7 @@ enum rtsp_read_request_response rtsp_read_request(rtsp_conn_info *conn, rtsp_mes
// metadata
if (warning_message_sent == 0) {
uint64_t time_now = get_absolute_time_in_fp();
uint64_t time_now = get_absolute_time_in_ns();
if (time_now > threshold_time) { // it's taking too long
debug(1, "Error receiving metadata from source -- transmission seems "
"to be stalled.");
@@ -2319,7 +2319,7 @@ static void *rtsp_conversation_thread_func(void *pconn) {
rtsp_conn_info *conn = pconn;
// create the watchdog mutex, initialise the watchdog time and start the watchdog thread;
conn->watchdog_bark_time = get_absolute_time_in_fp();
conn->watchdog_bark_time = get_absolute_time_in_ns();
pthread_mutex_init(&conn->watchdog_mutex, NULL);
pthread_create(&conn->player_watchdog_thread, NULL, &player_watchdog_thread_code, (void *)conn);
shairport.c
+8 -8
View File
@@ -143,10 +143,10 @@ void *soxr_time_check(__attribute__((unused)) void *arg) {
int i;
int number_of_iterations = 0;
uint64_t soxr_start_time = get_absolute_time_in_fp();
uint64_t soxr_start_time = get_absolute_time_in_ns();
uint64_t loop_until_time =
(uint64_t)0x180000000 + soxr_start_time; // loop for a second and a half, max -- no need to be able to cancel it, do _don't even try_!
while (get_absolute_time_in_fp() < loop_until_time) {
(uint64_t)1500000000 + soxr_start_time; // loop for a second and a half, max -- no need to be able to cancel it, do _don't even try_!
while (get_absolute_time_in_ns() < loop_until_time) {
number_of_iterations++;
for (i = 0; i < buffer_length; i++) {
@@ -184,11 +184,11 @@ void *soxr_time_check(__attribute__((unused)) void *arg) {
NULL, NULL); // Default configuration.
}
double soxr_execution_time_us =
(((get_absolute_time_in_fp() - soxr_start_time) * 1000000) >> 32) * 1.0;
double soxr_execution_time_ns =
(get_absolute_time_in_ns() - soxr_start_time) * 1.0;
// free(outbuffer);
// free(inbuffer);
config.soxr_delay_index = (int)(0.9 + soxr_execution_time_us / (number_of_iterations * 1000));
config.soxr_delay_index = (int)(0.9 + soxr_execution_time_ns / (number_of_iterations * 1000000));
debug(2, "soxr_delay_index: %d.", config.soxr_delay_index);
if ((config.packet_stuffing == ST_soxr) &&
(config.soxr_delay_index > config.soxr_delay_threshold))
@@ -1393,8 +1393,8 @@ int main(int argc, char **argv) {
conns = NULL; // no connections active
memset((void *)&main_thread_id, 0, sizeof(main_thread_id));
memset(&config, 0, sizeof(config)); // also clears all strings, BTW
fp_time_at_startup = get_absolute_time_in_fp();
fp_time_at_last_debug_message = fp_time_at_startup;
ns_time_at_startup = get_absolute_time_in_ns();
ns_time_at_last_debug_message = ns_time_at_startup;
// this is a bit weird, but necessary -- basename() may modify the argument passed in
char *basec = strdup(argv[0]);
char *bname = basename(basec);