Merge pull request #259 from mikebrady/modify_delay_check

Detect and handle when the packet buffers are exhausted. (!)
Modify the way `audio_alsa` gets delay information from the `alsa` subsystem.
Gracefully handle occasions when the delay information is unavailable or the delay returns a negative result.
Add an option to turn off synchronisation (this is probably temporary).
Add two options for setting `alsa` period size and `alsa` buffer size – advanced usage only.
Start to tidy up arithmetic errors due to sloppy observance of type mixing and promotion rules.
Add some `alsa` information to debug info.
Tidy up some debug messages; drop the priority of some and raise others.
This commit is contained in:
Mike Brady
2016-03-31 12:03:10 +01:00
11 changed files with 466 additions and 223 deletions
+1 -1
View File
@@ -88,7 +88,7 @@ Download Shairport Sync:
Next, `cd` into the shairport-sync directory and execute the following command:
```
$ git checkout development
$ git checkout modify_delay_check
$ autoreconf -i -f
```
(Note that the `autoreconf...` step may take some time on less powerful machines.)
+2 -1
View File
@@ -31,7 +31,8 @@ typedef struct {
// returns the delay before the next frame to be sent to the device would actually be audible.
// almost certainly wrong if the buffer is empty, so put silent buffers into it to make it busy.
// will change dynamically, so keep watching it. Implemented in ALSA only.
uint32_t (*delay)();
// returns a negative error code if there's a problem
int (*delay)(long* the_delay); // snd_pcm_sframes_t is a signed long
// may be NULL, in which case soft volume is applied
void (*volume)(double vol);
+167 -22
View File
@@ -42,7 +42,7 @@ static void start(int sample_rate);
static void play(short buf[], int samples);
static void stop(void);
static void flush(void);
static uint32_t delay(void);
int delay(long* the_delay);
static void volume(double vol);
static void linear_volume(double vol);
static void parameters(audio_parameters *info);
@@ -86,6 +86,11 @@ static int hardware_mixer = 0;
static int play_number;
static int64_t accumulated_delay, accumulated_da_delay;
int alsa_characteristics_already_listed = 0;
static snd_pcm_uframes_t period_size_requested,buffer_size_requested;
static int set_period_size_request,set_buffer_size_request;
static void help(void) {
printf(" -d output-device set the output device [default*|...]\n"
@@ -127,6 +132,9 @@ static int init(int argc, char **argv) {
const char *str;
int value;
set_period_size_request = 0;
set_buffer_size_request = 0;
config.audio_backend_latency_offset = 0; // this is the default for ALSA
config.audio_backend_buffer_desired_length =
6615; // default for alsa with a software mixer
@@ -182,7 +190,45 @@ static int init(int argc, char **argv) {
alsa_mix_ctrl = (char *)str;
hardware_mixer = 1;
}
/* Get the disable_synchronization setting. */
if (config_lookup_string(config.cfg, "alsa.disable_synchronization", &str)) {
if (strcasecmp(str, "no") == 0)
config.no_sync = 0;
else if (strcasecmp(str, "yes") == 0)
config.no_sync = 1;
else
die("Invalid disable_synchronization option choice \"%s\". It should be \"yes\" or \"no\"");
}
/* Get the optional period size value */
if (config_lookup_int(config.cfg, "alsa.period_size",
&value)) {
set_period_size_request = 1;
debug(1,"Value read for period size is %d.",value);
if (value < 0)
die("Invalid alsa period size setting \"%d\". It "
"must be greater than 0.",
value);
else
period_size_requested = value;
}
/* Get the optional buffer size value */
if (config_lookup_int(config.cfg, "alsa.buffer_size",
&value)) {
set_buffer_size_request = 1;
debug(1,"Value read for buffer size is %d.",value);
if (value < 0)
die("Invalid alsa buffer size setting \"%d\". It "
"must be greater than 0.",
value);
else
buffer_size_requested = value;
}
}
optind = 1; // optind=0 is equivalent to optind=1 plus special behaviour
argv--; // so we shift the arguments to satisfy getopt()
@@ -279,6 +325,7 @@ static int init(int argc, char **argv) {
snd_mixer_close(alsa_mix_handle);
}
alsa_mix_handle = NULL;
pthread_mutex_unlock(&alsa_mutex);
return 0;
@@ -347,10 +394,31 @@ int open_alsa_device(void) {
desired_sample_rate, snd_strerror(ret));
}
// snd_pcm_hw_params_set_period_size_near(alsa_handle, alsa_params, &frames,
// &dir);
// snd_pcm_hw_params_set_buffer_size_near(alsa_handle, alsa_params,
// &buffer_size);
if (set_period_size_request!=0) {
debug(1,"Attempting to set the period size");
ret = snd_pcm_hw_params_set_period_size_near(alsa_handle, alsa_params, &period_size_requested, &dir);
if (ret < 0) {
die("audio_alsa: cannot set period size of %lu: %s",
period_size_requested, snd_strerror(ret));
snd_pcm_uframes_t actual_period_size;
snd_pcm_hw_params_get_period_size(alsa_params, &actual_period_size, &dir);
if (actual_period_size!=period_size_requested)
inform("Actual period size set to a different value than requested. Requested: %lu, actual setting: %lu",period_size_requested,actual_period_size);
}
}
if (set_buffer_size_request!=0) {
debug(1,"Attempting to set the buffer size to %lu",buffer_size_requested);
ret = snd_pcm_hw_params_set_buffer_size_near(alsa_handle, alsa_params, &buffer_size_requested);
if (ret < 0) {
die("audio_alsa: cannot set buffer size of %lu: %s",
buffer_size_requested, snd_strerror(ret));
snd_pcm_uframes_t actual_buffer_size;
snd_pcm_hw_params_get_buffer_size(alsa_params, &actual_buffer_size);
if (actual_buffer_size!=buffer_size_requested)
inform("Actual period size set to a different value than requested. Requested: %lu, actual setting: %lu",buffer_size,actual_buffer_size);
}
}
ret = snd_pcm_hw_params(alsa_handle, alsa_params);
if (ret < 0) {
@@ -370,6 +438,7 @@ int open_alsa_device(void) {
if (actual_buffer_length <
config.audio_backend_buffer_desired_length + minimal_buffer_headroom) {
/*
// the dac buffer is too small, so let's try to set it
buffer_size =
config.audio_backend_buffer_desired_length + requested_buffer_headroom;
@@ -390,8 +459,81 @@ int open_alsa_device(void) {
requested_buffer_headroom,
buffer_size);
}
*/
debug(1,"The alsa buffer is to small (%lu bytes) to accommodate the desired backend buffer length (%ld) you have chosen.",actual_buffer_length,config.audio_backend_buffer_desired_length);
}
if ((alsa_characteristics_already_listed==0)) {
alsa_characteristics_already_listed=1;
int rc;
unsigned int val, val2;
int dir;
snd_pcm_uframes_t frames;
debug(1,"PCM handle name = '%s'",
snd_pcm_name(alsa_handle));
// ret = snd_pcm_hw_params_any(alsa_handle, alsa_params);
// if (ret < 0) {
// die("audio_alsa: Cannpot get configuration for device \"%s\": no configurations "
// "available",
// alsa_out_dev);
// }
snd_pcm_hw_params_get_access(alsa_params,
(snd_pcm_access_t *) &val);
debug(1,"access type = %s",
snd_pcm_access_name((snd_pcm_access_t)val));
snd_pcm_hw_params_get_format(alsa_params,(snd_pcm_format_t*)&val);
debug(1,"format = '%s' (%s)",
snd_pcm_format_name((snd_pcm_format_t)val),
snd_pcm_format_description(
(snd_pcm_format_t)val));
snd_pcm_hw_params_get_subformat(alsa_params,
(snd_pcm_subformat_t *)&val);
debug(1,"subformat = '%s' (%s)",
snd_pcm_subformat_name((snd_pcm_subformat_t)val),
snd_pcm_subformat_description(
(snd_pcm_subformat_t)val));
snd_pcm_hw_params_get_channels(alsa_params, &val);
debug(1,"channels = %d", val);
snd_pcm_hw_params_get_rate(alsa_params, &val, &dir);
debug(1,"rate = %d bps", val);
snd_pcm_hw_params_get_period_time(alsa_params,
&val, &dir);
debug(1,"period time = %d us", val);
snd_pcm_hw_params_get_period_size(alsa_params,
&frames, &dir);
debug(1,"period size = %d frames", (int)frames);
snd_pcm_hw_params_get_buffer_time(alsa_params,
&val, &dir);
debug(1,"buffer time = %d us", val);
snd_pcm_hw_params_get_buffer_size(alsa_params,
(snd_pcm_uframes_t *) &val);
debug(1,"buffer size = %d frames", val);
snd_pcm_hw_params_get_periods(alsa_params, &val, &dir);
debug(1,"periods per buffer = %d frames", val);
snd_pcm_hw_params_get_rate_numden(alsa_params,
&val, &val2);
debug(1,"exact rate = %d/%d bps", val, val2);
val = snd_pcm_hw_params_get_sbits(alsa_params);
debug(1,"significant bits = %d", val);
}
return (0);
}
@@ -402,41 +544,44 @@ static void start(int sample_rate) {
desired_sample_rate = sample_rate; // must be a variable
}
static uint32_t delay() {
int delay(long* the_delay) {
//snd_pcm_sframes_t is a signed long -- hence the return of a "long"
int reply;
// debug(3,"audio_alsa delay called.");
if (alsa_handle == NULL) {
return 0;
return -ENODEV;
} else {
pthread_mutex_lock(&alsa_mutex);
snd_pcm_sframes_t current_avail, current_delay = 0;
int derr, ignore;
if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_RUNNING) {
derr = snd_pcm_avail_delay(alsa_handle, &current_avail, &current_delay);
// current_avail not used
if (derr != 0) {
ignore = snd_pcm_recover(alsa_handle, derr, 0);
reply = snd_pcm_delay(alsa_handle, the_delay);
if (reply != 0) {
debug(1, "Error %d in delay(): %s. Delay reported is %d frames.", derr,
snd_strerror(derr), current_delay);
current_delay = -1;
snd_strerror(derr), *the_delay);
ignore = snd_pcm_recover(alsa_handle, derr, 0);
}
} else if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_PREPARED) {
current_delay = 0;
*the_delay = 0;
reply = 0; // no error
} else {
if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_XRUN)
current_delay = 0;
else {
current_delay = -1;
if (snd_pcm_state(alsa_handle) == SND_PCM_STATE_XRUN) {
*the_delay = 0;
reply = 0; // no error
} else {
reply = -EIO;
debug(1, "Error -- ALSA delay(): bad state: %d.",
snd_pcm_state(alsa_handle));
}
if ((derr = snd_pcm_prepare(alsa_handle))) {
ignore = snd_pcm_recover(alsa_handle, derr, 0);
debug(1, "Error preparing after delay error: %s.", snd_strerror(derr));
current_delay = -1;
}
}
pthread_mutex_unlock(&alsa_mutex);
return current_delay;
// here, occasionally pretend there's a problem with pcm_get_delay()
//if ((random() % 100000) < 3) // keep it pretty rare
// reply = -EPERM; // pretend something bad has happened
return reply;
}
}
@@ -459,9 +604,9 @@ static void play(short buf[], int samples) {
(snd_pcm_state(alsa_handle) == SND_PCM_STATE_RUNNING)) {
err = snd_pcm_writei(alsa_handle, (char *)buf, samples);
if (err < 0) {
ignore = snd_pcm_recover(alsa_handle, err, 0);
debug(1, "Error %d writing %d samples in play() %s.", err, samples,
snd_strerror(err));
ignore = snd_pcm_recover(alsa_handle, err, 0);
}
} else {
debug(1, "Error -- ALSA device in incorrect state (%d) for play.",
+1 -1
View File
@@ -478,7 +478,7 @@ uint64_t get_absolute_time_in_fp() {
struct timespec tn;
// can't use CLOCK_MONOTONIC_RAW as it's not implemented in OpenWrt
clock_gettime(CLOCK_MONOTONIC, &tn);
time_now_fp = ((uint64_t)tn.tv_sec << 32) + ((uint64_t)tn.tv_nsec << 32) / 1000000000;
time_now_fp = ((uint64_t)tn.tv_sec << 32) + ((uint64_t)tn.tv_nsec << 32) / 1000000000; // types okay
#endif
#ifdef COMPILE_FOR_OSX
uint64_t time_now_mach;
+3 -2
View File
@@ -57,6 +57,7 @@ typedef struct {
int udp_port_base;
int udp_port_range;
int ignore_volume_control;
int no_sync; // disable synchronisation, even if it's available
int resyncthreshold; // if it get's out of whack my more than this, resync. Zero means never
// resync.
int allow_session_interruption;
@@ -84,9 +85,9 @@ typedef struct {
char *logfile;
char *errfile;
char *configfile;
int32_t audio_backend_buffer_desired_length; // this will be the desired number of frames in the
long audio_backend_buffer_desired_length; // this will be the desired number of frames in the
// audio backend buffer -- the DAC buffer for ALSA
int32_t audio_backend_latency_offset; // this will be the offset to compensate for any fixed latency
long audio_backend_latency_offset; // this will be the offset to compensate for any fixed latency
uint32_t volume_range_db; // the range, in dB, from max dB to min dB. Zero means use the mixer's native range.
// there might be in the audio
} shairport_cfg;
+1 -1
View File
@@ -2,7 +2,7 @@
# Process this file with autoconf to produce a configure script.
AC_PREREQ([2.50])
AC_INIT([shairport-sync], [2.9.4], [mikebrady@eircom.net])
AC_INIT([shairport-sync], [2.9.5.4], [mikebrady@eircom.net])
AM_INIT_AUTOMAKE
AC_CONFIG_SRCDIR([shairport.c])
AC_CONFIG_HEADERS([config.h])
+185 -115
View File
@@ -104,7 +104,7 @@ static pthread_mutex_t vol_mutex = PTHREAD_MUTEX_INITIALIZER;
#define MAX_PACKET 2048
// DAC buffer occupancy stuff
#define DAC_BUFFER_QUEUE_MINIMUM_LENGTH 5000
#define DAC_BUFFER_QUEUE_MINIMUM_LENGTH 2000
typedef struct audio_buffer_entry { // decoded audio packets
int ready;
@@ -168,8 +168,8 @@ static inline seq_t PREDECESSOR(seq_t x) {
// anything with ORDINATE in it must be proctected by the ab_mutex
static inline int32_t ORDINATE(seq_t x) {
int32_t p = x & 0xffff;
int32_t q = ab_read & 0x0ffff;
int32_t p = x; // int32_t from seq_t, i.e. uint16_t, so okay
int32_t q = ab_read; // int32_t from seq_t, i.e. uint16_t, so okay
int32_t t = (p + 0x10000 - q) & 0xffff;
// we definitely will get a positive number in t at this point, but it might be a
// positive alias of a negative number, i.e. x might actually be "before" ab_read
@@ -445,13 +445,14 @@ static abuf_t *buffer_get_frame(void) {
abuf_t *abuf = 0;
int i;
abuf_t *curframe;
int notified_buffer_empty = 0; // diagnostic only
pthread_mutex_lock(&ab_mutex);
int wait;
int32_t dac_delay = 0;
long dac_delay = 0; // long because alsa returns a long
do {
// get the time
local_time_now = get_absolute_time_in_fp();
local_time_now = get_absolute_time_in_fp(); // type okay
// if config.timeout (default 120) seconds have elapsed since the last audio packet was
// received, then we should stop.
@@ -534,6 +535,7 @@ static abuf_t *buffer_get_frame(void) {
curframe = audio_buffer + BUFIDX(ab_read);
if (curframe->ready) {
notified_buffer_empty=0; // at least one buffer now -- diagnostic only.
if (ab_buffering) { // if we are getting packets but not yet forwarding them to the player
int have_sent_prefiller_silence; // set true when we have send some silent frames to the DAC
uint32_t reference_timestamp;
@@ -571,12 +573,16 @@ static abuf_t *buffer_get_frame(void) {
// if would be in sync. To do this, we would give it a latency offset of -100 ms, i.e.
// -4410 frames.
int64_t delta = ((int64_t)first_packet_timestamp - (int64_t)reference_timestamp);
first_packet_time_to_play =
reference_timestamp_time +
((delta + (int64_t)config.latency + (int64_t)config.audio_backend_latency_offset)
<< 32) /
44100;
int64_t delta = ((int64_t)first_packet_timestamp - (int64_t)reference_timestamp)+config.latency+config.audio_backend_latency_offset; // uint32_t to int64_t is okay and int32t to int64t promotion is okay.
if (delta>=0) {
uint64_t delta_fp_sec = (delta << 32) / 44100; // int64_t which is positive
first_packet_time_to_play=reference_timestamp_time+delta_fp_sec;
} else {
int64_t abs_delta = -delta;
uint64_t delta_fp_sec = (abs_delta << 32) / 44100; // int64_t which is positive
first_packet_time_to_play=reference_timestamp_time-delta_fp_sec;
}
if (local_time_now >= first_packet_time_to_play) {
debug(
@@ -589,15 +595,19 @@ static abuf_t *buffer_get_frame(void) {
if (first_packet_time_to_play != 0) {
// recalculate first_packet_time_to_play -- the latency might change
int64_t delta = ((int64_t)first_packet_timestamp - (int64_t)reference_timestamp);
first_packet_time_to_play =
reference_timestamp_time +
((delta + (int64_t)config.latency + (int64_t)config.audio_backend_latency_offset)
<< 32) /
44100;
int64_t delta = ((int64_t)first_packet_timestamp - (int64_t)reference_timestamp)+config.latency+config.audio_backend_latency_offset; // uint32_t to int64_t is okay and int32t to int64t promotion is okay.
if (delta>=0) {
uint64_t delta_fp_sec = (delta << 32) / 44100; // int64_t which is positive
first_packet_time_to_play=reference_timestamp_time+delta_fp_sec;
} else {
int64_t abs_delta = -delta;
uint64_t delta_fp_sec = (abs_delta << 32) / 44100; // int64_t which is positive
first_packet_time_to_play=reference_timestamp_time-delta_fp_sec;
}
uint32_t max_dac_delay = 4410;
uint32_t filler_size = max_dac_delay; // 0.1 second -- the maximum we'll add to the DAC
int64_t max_dac_delay = 4410;
int64_t filler_size = max_dac_delay; // 0.1 second -- the maximum we'll add to the DAC
if (local_time_now >= first_packet_time_to_play) {
// we've gone past the time...
@@ -613,15 +623,16 @@ static abuf_t *buffer_get_frame(void) {
first_packet_time_to_play = 0;
time_since_play_started = 0;
} else {
// first_packet_time_to_play is definitely later than local_time_now
if ((config.output->delay) && (have_sent_prefiller_silence != 0)) {
dac_delay = config.output->delay();
if (dac_delay == -1) {
debug(1, "Error getting dac_delay in buffer_get_frame.");
int resp = config.output->delay(&dac_delay);
if (resp != 0) {
debug(1, "Error %d getting dac_delay in buffer_get_frame.",resp);
dac_delay = 0;
}
}
} else
dac_delay = 0;
uint64_t gross_frame_gap =
int64_t gross_frame_gap =
((first_packet_time_to_play - local_time_now) * 44100) >> 32;
int64_t exact_frame_gap = gross_frame_gap - dac_delay;
if (exact_frame_gap <= 0) {
@@ -636,7 +647,7 @@ static abuf_t *buffer_get_frame(void) {
first_packet_timestamp = 0;
first_packet_time_to_play = 0;
} else {
uint32_t fs = filler_size;
int64_t fs = filler_size;
if (fs > (max_dac_delay - dac_delay))
fs = max_dac_delay - dac_delay;
if ((exact_frame_gap <= fs) || (exact_frame_gap <= frame_size * 2)) {
@@ -648,6 +659,7 @@ static abuf_t *buffer_get_frame(void) {
ab_buffering = 0;
}
signed short *silence;
// fs will be truncated here
silence = malloc(FRAME_BYTES(fs));
memset(silence, 0, FRAME_BYTES(fs));
// debug(1,"Exact frame gap is %llu; play %d frames of silence. Dac_delay is %d,
@@ -656,6 +668,7 @@ static abuf_t *buffer_get_frame(void) {
free(silence);
have_sent_prefiller_silence = 1;
if (ab_buffering == 0) {
// not the time of the playing of the first frame
uint64_t reference_timestamp_time; // don't need this...
get_reference_timestamp_stuff(&play_segment_reference_frame, &reference_timestamp_time, &play_segment_reference_frame_remote_time);
#ifdef CONFIG_METADATA
@@ -686,21 +699,21 @@ static abuf_t *buffer_get_frame(void) {
do_wait = 1; // if the current frame exists and is ready, then wait unless it's time to let it go...
uint32_t reference_timestamp;
uint64_t reference_timestamp_time,remote_reference_timestamp_time;
get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time);
get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time); // all types okay
if (reference_timestamp) { // if we have a reference time
uint32_t packet_timestamp = curframe->timestamp;
int64_t delta = ((int64_t)packet_timestamp - (int64_t)reference_timestamp);
int64_t offset = (int64_t)config.latency + config.audio_backend_latency_offset -
(int64_t)config.audio_backend_buffer_desired_length;
int64_t net_offset = delta + offset;
int64_t time_to_play = reference_timestamp_time;
int64_t net_offset_fp_sec;
uint32_t packet_timestamp = curframe->timestamp; // types okay
int64_t delta = (int64_t)packet_timestamp - (int64_t)reference_timestamp; // uint32_t to int64_t is okay.
int64_t offset = config.latency + config.audio_backend_latency_offset -
config.audio_backend_buffer_desired_length; // all arguments are int32_t, so expression promotion okay
int64_t net_offset = delta + offset; // okay
uint64_t time_to_play = reference_timestamp_time; // type okay
if (net_offset >= 0) {
net_offset_fp_sec = (net_offset << 32) / 44100;
uint64_t net_offset_fp_sec = (net_offset << 32) / 44100; // int64_t which is positive
time_to_play += net_offset_fp_sec; // using the latency requested...
// debug(2,"Net Offset: %lld, adjusted: %lld.",net_offset,net_offset_fp_sec);
} else {
net_offset_fp_sec = ((-net_offset) << 32) / 44100;
int64_t abs_net_offset = -net_offset;
uint64_t net_offset_fp_sec = (abs_net_offset << 32) / 44100; // int64_t which is positive
time_to_play -= net_offset_fp_sec;
// debug(2,"Net Offset: %lld, adjusted: -%lld.",net_offset,net_offset_fp_sec);
}
@@ -710,6 +723,14 @@ static abuf_t *buffer_get_frame(void) {
}
}
}
if (do_wait==0)
if ((ab_synced!=0) && (ab_read==ab_write)) { // the buffer is empty!
if (notified_buffer_empty==0) {
debug(1,"All buffers exhausted!");
notified_buffer_empty=1;
}
do_wait=1;
}
wait = (ab_buffering || (do_wait != 0) || (!ab_synced)) && (!please_stop);
if (wait) {
@@ -766,6 +787,7 @@ static abuf_t *buffer_get_frame(void) {
}
}
if (!curframe->ready) {
// debug(1, "Supplying a silent frame for frame %u", read);
missing_packets++;
@@ -935,9 +957,9 @@ static void *player_thread_func(void *arg) {
int64_t tsum_of_sync_errors, tsum_of_corrections, tsum_of_insertions_and_deletions,
tsum_of_drifts;
int64_t previous_sync_error, previous_correction;
int64_t minimum_dac_queue_size = 1000000;
int32_t minimum_buffer_occupancy = BUFFER_FRAMES;
int32_t maximum_buffer_occupancy = 0;
int64_t minimum_dac_queue_size = INT64_MAX;
int32_t minimum_buffer_occupancy = INT32_MAX;
int32_t maximum_buffer_occupancy = INT32_MIN;
buffer_occupancy = 0;
@@ -992,25 +1014,29 @@ static void *player_thread_func(void *arg) {
uint32_t reference_timestamp;
uint64_t reference_timestamp_time,remote_reference_timestamp_time;
get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time);
get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time); // types okay
int64_t rt, nt;
rt = reference_timestamp;
nt = inframe->timestamp;
rt = reference_timestamp; // uint32_t to int64_t
nt = inframe->timestamp; // uint32_t to int64_t
uint64_t local_time_now = get_absolute_time_in_fp();
uint64_t local_time_now = get_absolute_time_in_fp(); // types okay
// struct timespec tn;
// clock_gettime(CLOCK_MONOTONIC,&tn);
// uint64_t
// local_time_now=((uint64_t)tn.tv_sec<<32)+((uint64_t)tn.tv_nsec<<32)/1000000000;
int64_t td_in_frames;
int64_t td = local_time_now - reference_timestamp_time;
int64_t td = 0;
int64_t td_in_frames = 0;
if (local_time_now >= reference_timestamp_time) {
// debug(1,"td is %lld.",td);
if (td >= 0) {
td = local_time_now - reference_timestamp_time; // this is the positive value. Conversion is positive uint64_t to int64_t, thus okay
td_in_frames = (td * 44100) >> 32;
} else {
td_in_frames = -((-td * 44100) >> 32);
td = reference_timestamp_time - local_time_now; // this is the absolute value, which should be negated. Conversion is positive uint64_t to int64_t, thus okay.
td_in_frames = (td * 44100) >> 32; //use the absolute td value for the present. Types okay
td_in_frames = -td_in_frames;
td = -td; // should be okay, as the range of values should be very small w.r.t 64 bits
}
// This is the timing error for the next audio frame in the DAC, if applicable
@@ -1020,19 +1046,19 @@ static void *player_thread_func(void *arg) {
// check sequencing
if (last_seqno_read == -1)
last_seqno_read = inframe->sequence_number;
last_seqno_read = inframe->sequence_number; //int32_t from seq_t, i.e. uint16_t, so okay.
else {
last_seqno_read = (SUCCESSOR(last_seqno_read) & 0xffff);
if (inframe->sequence_number != last_seqno_read) {
last_seqno_read = SUCCESSOR(last_seqno_read); // int32_t from seq_t, i.e. uint16_t, so okay.
if (inframe->sequence_number != last_seqno_read) { //seq_t, ei.e. uint16_t and int32_t, so okay
debug(
1,
"Player: packets out of sequence: expected: %d, got: %d, sync error: %d frames.",
last_seqno_read, inframe->sequence_number, sync_error);
"Player: packets out of sequence: expected: %u, got: %u, with ab_read: %u and ab_write: %u.",
last_seqno_read, inframe->sequence_number,ab_read,ab_write);
last_seqno_read = inframe->sequence_number; // reset warning...
}
}
buffer_occupancy = seq_diff(ab_read, ab_write);
buffer_occupancy = seq_diff(ab_read, ab_write); // int32_t from int32
if (buffer_occupancy < minimum_buffer_occupancy)
minimum_buffer_occupancy = buffer_occupancy;
@@ -1040,26 +1066,46 @@ static void *player_thread_func(void *arg) {
if (buffer_occupancy > maximum_buffer_occupancy)
maximum_buffer_occupancy = buffer_occupancy;
if (config.output->delay) {
current_delay = config.output->delay();
if (current_delay == -1) {
debug(1, "Delay error when checking running latency.");
current_delay = 0;
}
if (current_delay < minimum_dac_queue_size)
minimum_dac_queue_size = current_delay;
// here, we want to check (a) if we are meant to do synchronisation, (b) if we have a delay procedure, (b) if we can get the delay.
// If any of these are false, we don't do any synchronisation stuff
int resp = -1; // use this as a flag -- if negative, we can't rely on a real known delay
current_delay = -1; // use this as a failure flag
if (config.output->delay) {
long l_delay;
resp = config.output->delay(&l_delay);
current_delay = l_delay;
if (resp==0) { // no error
if (current_delay<0) {
debug(1,"Underrun of %d frames reported, but ignored.",current_delay);
current_delay=0; // could get a negative value if there was underrun, but ignore it.
}
if (current_delay < minimum_dac_queue_size) {
minimum_dac_queue_size = current_delay; // update for display later
}
} else {
debug(1, "Delay error %d when checking running latency.",resp);
}
}
if (resp >= 0) {
// this is the actual delay, including the latency we actually want, which will
// fluctuate a good bit about a potentially rising or falling trend.
int64_t delay = td_in_frames + rt - (nt - current_delay);
int64_t delay = td_in_frames + rt - (nt - current_delay); // all int64_t
// This is the timing error for the next audio frame in the DAC.
sync_error = delay - config.latency;
sync_error = delay - config.latency; // int64_t from int64_t - int32_t, so okay
// if (llabs(sync_error)>352*512)
// debug(1,"Very large sync error: %lld",sync_error);
// before we finally commit to this frame, check its sequencing and timing
// require a certain error before bothering to fix it...
if (sync_error > config.tolerance) {
if (sync_error > config.tolerance) { // int64_t > int, okay
amount_to_stuff = -1;
}
if (sync_error < -config.tolerance) {
@@ -1079,7 +1125,7 @@ static void *player_thread_func(void *arg) {
if (amount_to_stuff) {
if ((local_time_now) && (first_packet_time_to_play) && (local_time_now >= first_packet_time_to_play)) {
int64_t tp = (local_time_now - first_packet_time_to_play)>>32; // seconds
int64_t tp = (local_time_now - first_packet_time_to_play)>>32; // seconds int64_t from uint64_t which is always positive, so ok
if (tp<5)
amount_to_stuff = 0; // wait at least five seconds
@@ -1089,6 +1135,9 @@ static void *player_thread_func(void *arg) {
}
}
}
if (config.no_sync!=0)
amount_to_stuff = 0 ; // no stuffing if it's been disabled
if ((amount_to_stuff == 0) && (fix_volume == 0x10000)) {
// if no stuffing needed and no volume adjustment, then
@@ -1132,8 +1181,14 @@ static void *player_thread_func(void *arg) {
// check for loss of sync
// timestamp of zero means an inserted silent frame in place of a missing frame
if ((inframe->timestamp != 0) && (!please_stop) && (config.resyncthreshold != 0) &&
(abs(sync_error) > config.resyncthreshold)) {
// not too sure if abs() is implemented for int64_t, so we'll do it manually
int64_t abs_sync_error = sync_error;
if (abs_sync_error<0)
abs_sync_error = -abs_sync_error;
if ((config.no_sync==0) && (inframe->timestamp != 0) && (!please_stop) && (config.resyncthreshold != 0) &&
(abs_sync_error > config.resyncthreshold)) {
sync_error_out_of_bounds++;
// debug(1,"Sync error out of bounds: Error: %lld; previous error: %lld; DAC: %lld;
// timestamp: %llx, time now
@@ -1149,11 +1204,12 @@ static void *player_thread_func(void *arg) {
sync_error_out_of_bounds = 0;
}
} else {
// if there is no delay procedure, there can be no synchronising
// if there is no delay procedure, or it's not working or not allowed, there can be no synchronising
if (fix_volume == 0x10000)
config.output->play(inbuf, frame_size);
else {
play_samples = stuff_buffer_basic(inbuf, outbuf, 0);
play_samples = stuff_buffer_basic(inbuf, outbuf, 0); // no stuffing, but volume adjustment
config.output->play(outbuf, frame_size);
}
}
@@ -1166,45 +1222,49 @@ static void *player_thread_func(void *arg) {
// new stats calculation. We want a running average of sync error, drift, adjustment,
// number of additions+subtractions
// this is a misleading hack -- the statistics should include some data on the number of valid samples and the number of times sync wasn't checked due to non availability of a delay figure.
// for the present, stats are only updated when sync has been checked
if (sync_error!=-1) {
if (number_of_statistics == trend_interval) {
// here we remove the oldest statistical data and take it from the summaries as well
tsum_of_sync_errors -= statistics[oldest_statistic].sync_error;
tsum_of_drifts -= statistics[oldest_statistic].drift;
if (statistics[oldest_statistic].correction > 0)
tsum_of_insertions_and_deletions -= statistics[oldest_statistic].correction;
else
tsum_of_insertions_and_deletions += statistics[oldest_statistic].correction;
tsum_of_corrections -= statistics[oldest_statistic].correction;
oldest_statistic = (oldest_statistic + 1) % trend_interval;
number_of_statistics--;
}
if (number_of_statistics == trend_interval) {
// here we remove the oldest statistical data and take it from the summaries as well
tsum_of_sync_errors -= statistics[oldest_statistic].sync_error;
tsum_of_drifts -= statistics[oldest_statistic].drift;
if (statistics[oldest_statistic].correction > 0)
tsum_of_insertions_and_deletions -= statistics[oldest_statistic].correction;
statistics[newest_statistic].sync_error = sync_error;
statistics[newest_statistic].correction = amount_to_stuff;
if (number_of_statistics == 0)
statistics[newest_statistic].drift = 0;
else
tsum_of_insertions_and_deletions += statistics[oldest_statistic].correction;
tsum_of_corrections -= statistics[oldest_statistic].correction;
oldest_statistic = (oldest_statistic + 1) % trend_interval;
number_of_statistics--;
}
statistics[newest_statistic].drift =
sync_error - previous_sync_error - previous_correction;
statistics[newest_statistic].sync_error = sync_error;
statistics[newest_statistic].correction = amount_to_stuff;
previous_sync_error = sync_error;
previous_correction = amount_to_stuff;
if (number_of_statistics == 0)
statistics[newest_statistic].drift = 0;
else
statistics[newest_statistic].drift =
sync_error - previous_sync_error - previous_correction;
previous_sync_error = sync_error;
previous_correction = amount_to_stuff;
tsum_of_sync_errors += sync_error;
tsum_of_drifts += statistics[newest_statistic].drift;
if (amount_to_stuff > 0) {
tsum_of_insertions_and_deletions += amount_to_stuff;
} else {
tsum_of_insertions_and_deletions -= amount_to_stuff;
}
tsum_of_corrections += amount_to_stuff;
session_corrections += amount_to_stuff;
tsum_of_sync_errors += sync_error;
tsum_of_drifts += statistics[newest_statistic].drift;
if (amount_to_stuff > 0) {
tsum_of_insertions_and_deletions += amount_to_stuff;
} else {
tsum_of_insertions_and_deletions -= amount_to_stuff;
}
tsum_of_corrections += amount_to_stuff;
session_corrections += amount_to_stuff;
newest_statistic = (newest_statistic + 1) % trend_interval;
number_of_statistics++;
newest_statistic = (newest_statistic + 1) % trend_interval;
number_of_statistics++;
}
}
if (play_number % print_interval == 0) {
// we can now calculate running averages for sync error (frames), corrections (ppm),
@@ -1217,29 +1277,39 @@ static void *player_thread_func(void *arg) {
// if ((play_number/print_interval)%20==0)
if (config.statistics_requested) {
if (at_least_one_frame_seen) {
if (config.output->delay)
inform("Sync error: %.1f (frames); net correction: %.1f (ppm); corrections: %.1f "
"(ppm); missing packets %llu; late packets %llu; too late packets %llu; "
"resend requests %llu; min DAC queue size %lli, min and max buffer occupancy "
"%d and %d.",
moving_average_sync_error, moving_average_correction * 1000000 / 352,
moving_average_insertions_plus_deletions * 1000000 / 352, missing_packets,
late_packets, too_late_packets, resend_requests, minimum_dac_queue_size,
minimum_buffer_occupancy, maximum_buffer_occupancy);
else
if ((config.output->delay)) {
if (config.no_sync==0) {
inform("Sync error: %.1f (frames); net correction: %.1f (ppm); corrections: %.1f "
"(ppm); missing packets %llu; late packets %llu; too late packets %llu; "
"resend requests %llu; min DAC queue size %lli, min and max buffer occupancy "
"%d and %d.",
moving_average_sync_error, moving_average_correction * 1000000 / 352,
moving_average_insertions_plus_deletions * 1000000 / 352, missing_packets,
late_packets, too_late_packets, resend_requests, minimum_dac_queue_size,
minimum_buffer_occupancy, maximum_buffer_occupancy);
} else {
inform("Synchronisation disabled. Sync error: %.1f (frames); missing packets %llu; late packets %llu; too late packets %llu; "
"resend requests %llu; min DAC queue size %lli, min and max buffer occupancy "
"%d and %d.",
moving_average_sync_error, missing_packets,
late_packets, too_late_packets, resend_requests, minimum_dac_queue_size,
minimum_buffer_occupancy, maximum_buffer_occupancy);
}
} else {
inform("Synchronisation disabled. Missing packets %llu; late packets %llu; too late packets %llu; "
"resend requests %llu; min and max buffer occupancy "
"%d and %d.",
missing_packets,
late_packets, too_late_packets, resend_requests,
minimum_buffer_occupancy, maximum_buffer_occupancy);
minimum_buffer_occupancy, maximum_buffer_occupancy);
}
} else {
inform("No frames received in the last sampling interval.");
}
}
minimum_dac_queue_size = 1000000; // hack reset
maximum_buffer_occupancy = 0; // can't be less than this
minimum_buffer_occupancy = BUFFER_FRAMES; // can't be more than this
minimum_dac_queue_size = INT64_MAX; // hack reset
maximum_buffer_occupancy = INT32_MIN; // can't be less than this
minimum_buffer_occupancy = INT32_MAX; // can't be more than this
at_least_one_frame_seen = 0;
}
}
+7 -6
View File
@@ -124,7 +124,7 @@ void *rtp_audio_receiver(void *arg) {
stat_mean += stat_delta/stat_n;
stat_M2 += stat_delta*(time_interval_us - stat_mean);
if (stat_n % 2500 == 0) {
debug(3,"Packet reception intervals: mean, standard deviation and max for the last 2,500 packets in microseconds: %10.1f, %10.1f, %10.1f.",stat_mean, sqrtf(stat_M2 / (stat_n-1)),longest_packet_time_interval_us);
debug(2,"Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: %10.1f, %10.1f, %10.1f.",stat_mean, sqrtf(stat_M2 / (stat_n-1)),longest_packet_time_interval_us);
stat_n = 0;
stat_mean = 0.0;
stat_M2 = 0.0;
@@ -513,10 +513,10 @@ void *rtp_timing_receiver(void *arg) {
source_drift_usec = 0;
source_drift_usec = (source_drift_usec*1000000)>>32; // turn it to microseconds
int64_t current_delay = 0;
if (config.output->delay) {
current_delay = config.output->delay();
}
//long current_delay = 0;
//if (config.output->delay) {
// config.output->delay(&current_delay);
//}
// Useful for troubleshooting:
// clock_drift between source and local clock -- +ve means source is faster
// session_corrections -- the amount of correction done, in microseconds. +ve means frames added
@@ -524,7 +524,7 @@ void *rtp_timing_receiver(void *arg) {
// source_drift_usec = how much faster (+ve) or slower the source DAC is running relative to the source clock
// buffer_occupancy = the number of buffers occupied. Crude, but should show no long term trend if source and device are in sync.
// return_time = the time from soliciting a timing packet to getting it back. It should be short ( < 5 ms) and pretty consistent.
// debug(1, "%lld\t%lld\t%lld\t%lld\t%u\t%llu", clock_drift_in_usec,(session_corrections*1000000)/44100,current_delay,source_drift_usec,buffer_occupancy,(return_time*1000000)>>32);
// debug(1, "%lld\t%lld\t%ld\t%lld\t%u\t%llu", clock_drift_in_usec,(session_corrections*1000000)/44100,current_delay,source_drift_usec,buffer_occupancy,(return_time*1000000)>>32);
} else {
debug(1, "Timing port -- Unknown RTP packet of type 0x%02X length %d.", packet[1], nread);
@@ -700,6 +700,7 @@ void rtp_setup(SOCKADDR *remote, int cport, int tport, uint32_t active_remote, i
}
void get_reference_timestamp_stuff(uint32_t *timestamp, uint64_t *timestamp_time, uint64_t *remote_timestamp_time) {
// types okay
pthread_mutex_lock(&reference_time_mutex);
*timestamp = reference_timestamp;
*timestamp_time = reference_timestamp_time;
+1 -1
View File
@@ -293,7 +293,7 @@ static void cleanup_threads(void) {
if (conns[i]->running == 0) {
pthread_join(conns[i]->thread, &retval);
free(conns[i]);
debug(2, "one thread joined...");
debug(3, "one thread joined...");
nconns--;
if (nconns)
conns[i] = conns[nconns];
+3
View File
@@ -48,6 +48,9 @@ alsa =
// mixer_device = "default"; // the mixer_device default is whatever the output_device is. Normally you wouldn't have to use this.
// audio_backend_latency_offset = 0; // Set this offset to compensate for a fixed delay in the audio back end. E.g. if the output device delays by 100 ms, set this to -4410.
// audio_backend_buffer_desired_length = 6615; // If set too small, buffer underflow occurs on low-powered machines. Too long and the response times with software mixer become annoying.
// disable_synchronization = "no"; // Set to "yes" to disable synchronization. Default is "no".
// period_size = <number>; // Use this optional advanced setting to set the alsa period size near to this value
// buffer_size = <number>; // Use this optional advanced setting to set the alsa buffer size near to this value
};
// These are parameters for the "pipe" audio back end, a back end that directs raw CD-style audio output to a pipe. No interpolation is done.
+95 -73
View File
@@ -79,7 +79,7 @@ static void sig_ignore(int foo, siginfo_t *bar, void *baz) {}
static void sig_shutdown(int foo, siginfo_t *bar, void *baz) {
debug(1, "shutdown requested...");
shairport_shutdown();
daemon_log(LOG_NOTICE, "exit...");
// daemon_log(LOG_NOTICE, "exit...");
daemon_retval_send(255);
daemon_pid_file_remove();
exit(0);
@@ -104,52 +104,64 @@ static void sig_connect_audio_output(int foo, siginfo_t *bar, void *baz) {
set_requested_connection_state_to_output(1);
}
char* get_version_string() {
char* version_string = malloc(200);
if (version_string) {
strcpy(version_string, PACKAGE_VERSION);
#ifdef HAVE_LIBPOLARSSL
strcat(version_string, "-polarssl");
#endif
#ifdef HAVE_LIBSSL
strcat(version_string, "-openssl");
#endif
#ifdef CONFIG_TINYSVCMDNS
strcat(version_string, "-tinysvcmdns");
#endif
#ifdef CONFIG_AVAHI
strcat(version_string, "-Avahi");
#endif
#ifdef CONFIG_DNS_SD
strcat(version_string, "-dns_sd");
#endif
#ifdef CONFIG_ALSA
strcat(version_string, "-ALSA");
#endif
#ifdef CONFIG_SNDIO
strcat(version_string, "-sndio");
#endif
#ifdef CONFIG_AO
strcat(version_string, "-ao");
#endif
#ifdef CONFIG_PULSE
strcat(version_string, "-pulse");
#endif
#ifdef CONFIG_DUMMY
strcat(version_string, "-dummy");
#endif
#ifdef CONFIG_STDOUT
strcat(version_string, "-stdout");
#endif
#ifdef CONFIG_PIPE
strcat(version_string, "-pipe");
#endif
#ifdef HAVE_LIBSOXR
strcat(version_string, "-soxr");
#endif
#ifdef CONFIG_METADATA
strcat(version_string, "-metadata");
#endif
}
return version_string;
}
void print_version(void) {
char version_string[200];
strcpy(version_string, PACKAGE_VERSION);
#ifdef HAVE_LIBPOLARSSL
strcat(version_string, "-polarssl");
#endif
#ifdef HAVE_LIBSSL
strcat(version_string, "-openssl");
#endif
#ifdef CONFIG_TINYSVCMDNS
strcat(version_string, "-tinysvcmdns");
#endif
#ifdef CONFIG_AVAHI
strcat(version_string, "-Avahi");
#endif
#ifdef CONFIG_DNS_SD
strcat(version_string, "-dns_sd");
#endif
#ifdef CONFIG_ALSA
strcat(version_string, "-ALSA");
#endif
#ifdef CONFIG_SNDIO
strcat(version_string, "-sndio");
#endif
#ifdef CONFIG_AO
strcat(version_string, "-ao");
#endif
#ifdef CONFIG_PULSE
strcat(version_string, "-pulse");
#endif
#ifdef CONFIG_DUMMY
strcat(version_string, "-dummy");
#endif
#ifdef CONFIG_STDOUT
strcat(version_string, "-stdout");
#endif
#ifdef CONFIG_PIPE
strcat(version_string, "-pipe");
#endif
#ifdef HAVE_LIBSOXR
strcat(version_string, "-soxr");
#endif
#ifdef CONFIG_METADATA
strcat(version_string, "-metadata");
#endif
printf("%s\n", version_string);
char* version_string = get_version_string();
if (version_string) {
printf("%s\n", version_string);
free(version_string);
} else {
debug(1,"Can't print version string!");
}
}
void usage(char *progname) {
@@ -851,7 +863,7 @@ int main(int argc, char **argv) {
}
config.output->init(argc - audio_arg, argv + audio_arg);
daemon_log(LOG_NOTICE, "startup");
// daemon_log(LOG_NOTICE, "startup");
switch (endianness) {
case SS_LITTLE_ENDIAN:
@@ -907,47 +919,57 @@ int main(int argc, char **argv) {
inform("Please remove this setting and use the relevant audio_backend_latency_offset setting, if necessary, to compensate for delays elsewhere.");
}
/* print out version */
char* version_dbs = get_version_string();
if (version_dbs) {
debug(1,"Version: \"%s\"",version_dbs);
free(version_dbs);
} else {
debug(1,"Can't print the version information!");
}
/* Print out options */
debug(2, "statistics_requester status is %d.", config.statistics_requested);
debug(2, "daemon status is %d.", config.daemonise);
debug(2, "rtsp listening port is %d.", config.port);
debug(2, "udp base port is %d.", config.udp_port_base);
debug(2, "udp port range is %d.", config.udp_port_range);
debug(2, "Shairport Sync player name is \"%s\".", config.apname);
debug(2, "Audio Output name is \"%s\".", config.output_name);
debug(2, "on-start action is \"%s\".", config.cmd_start);
debug(2, "on-stop action is \"%s\".", config.cmd_stop);
debug(2, "wait-cmd status is %d.", config.cmd_blocking);
debug(2, "mdns backend \"%s\".", config.mdns_name);
debug(1, "statistics_requester status is %d.", config.statistics_requested);
debug(1, "daemon status is %d.", config.daemonise);
debug(1, "rtsp listening port is %d.", config.port);
debug(1, "udp base port is %d.", config.udp_port_base);
debug(1, "udp port range is %d.", config.udp_port_range);
debug(1, "Shairport Sync player name is \"%s\".", config.apname);
debug(1, "Audio Output name is \"%s\".", config.output_name);
debug(1, "on-start action is \"%s\".", config.cmd_start);
debug(1, "on-stop action is \"%s\".", config.cmd_stop);
debug(1, "wait-cmd status is %d.", config.cmd_blocking);
debug(1, "mdns backend \"%s\".", config.mdns_name);
debug(2, "userSuppliedLatency is %d.", config.userSuppliedLatency);
debug(2, "AirPlayLatency is %d.", config.AirPlayLatency);
debug(2, "iTunesLatency is %d.", config.iTunesLatency);
debug(2, "forkedDaapdLatency is %d.", config.ForkedDaapdLatency);
debug(2, "stuffing option is \"%d\".", config.packet_stuffing);
debug(2, "resync time is %d.", config.resyncthreshold);
debug(2, "allow a session to be interrupted: %d.", config.allow_session_interruption);
debug(2, "busy timeout time is %d.", config.timeout);
debug(2, "tolerance is %d frames.", config.tolerance);
debug(2, "password is \"%s\".", config.password);
debug(2, "ignore_volume_control is %d.", config.ignore_volume_control);
debug(2, "audio backend desired buffer length is %d.",
debug(1, "stuffing option is \"%d\".", config.packet_stuffing);
debug(1, "resync time is %d.", config.resyncthreshold);
debug(1, "allow a session to be interrupted: %d.", config.allow_session_interruption);
debug(1, "busy timeout time is %d.", config.timeout);
debug(1, "drift tolerance is %d frames.", config.tolerance);
debug(1, "password is \"%s\".", config.password);
debug(1, "ignore_volume_control is %d.", config.ignore_volume_control);
debug(1, "disable_synchronization is %d.", config.no_sync);
debug(1, "audio backend desired buffer length is %d.",
config.audio_backend_buffer_desired_length);
debug(2, "audio backend latency offset is %d.", config.audio_backend_latency_offset);
debug(2, "volume range in dB (zero means use the range specified by the mixer): %u.", config.volume_range_db);
debug(1, "audio backend latency offset is %d.", config.audio_backend_latency_offset);
debug(1, "volume range in dB (zero means use the range specified by the mixer): %u.", config.volume_range_db);
char *realConfigPath = realpath(config.configfile,NULL);
if (realConfigPath) {
debug(2, "configuration file name \"%s\" resolves to \"%s\".", config.configfile,realConfigPath);
debug(1, "configuration file name \"%s\" resolves to \"%s\".", config.configfile,realConfigPath);
free(realConfigPath);
} else {
debug(2, "configuration file name \"%s\" can not be resolved.", config.configfile);
debug(1, "configuration file name \"%s\" can not be resolved.", config.configfile);
}
#ifdef CONFIG_METADATA
debug(2, "metdata enabled is %d.", config.metadata_enabled);
debug(2, "metadata pipename is \"%s\".", config.metadata_pipename);
debug(2, "get-coverart is %d.", config.get_coverart);
debug(1, "metdata enabled is %d.", config.metadata_enabled);
debug(1, "metadata pipename is \"%s\".", config.metadata_pipename);
debug(1, "get-coverart is %d.", config.get_coverart);
#endif
uint8_t ap_md5[16];