Add timing to debug messages, make timing sender wait interruptable eveyr 20 ms, thus making TEARDOWN faster.
This commit is contained in:
Mike Brady
@@ -25,6 +25,8 @@
|
||||
* OTHER DEALINGS IN THE SOFTWARE.
|
||||
*/
|
||||
|
||||
#include "common.h"
|
||||
#include <assert.h>
|
||||
#include <errno.h>
|
||||
#include <memory.h>
|
||||
#include <poll.h>
|
||||
@@ -37,8 +39,6 @@
|
||||
#include <sys/wait.h>
|
||||
#include <time.h>
|
||||
#include <unistd.h>
|
||||
#include "common.h"
|
||||
#include <assert.h>
|
||||
|
||||
#ifdef COMPILE_FOR_OSX
|
||||
#include <CoreServices/CoreServices.h>
|
||||
@@ -124,11 +124,25 @@ void debug(int level, const char *format, ...) {
|
||||
return;
|
||||
char s[1024];
|
||||
s[0] = 0;
|
||||
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 divisor = (uint64_t)1 << 32;
|
||||
double tss = 1.0 * time_since_start / divisor;
|
||||
double tsl = 1.0 * time_since_last_debug_message / divisor;
|
||||
va_list args;
|
||||
va_start(args, format);
|
||||
vsnprintf(s, sizeof(s), format, args);
|
||||
va_end(args);
|
||||
daemon_log(LOG_DEBUG, "%s", s);
|
||||
if ((config.debugger_show_elapsed_time) && (config.debugger_show_relative_time))
|
||||
daemon_log(LOG_DEBUG, "|% 20.9f|% 20.9f|%s", tss, tsl, s);
|
||||
else if (config.debugger_show_relative_time)
|
||||
daemon_log(LOG_DEBUG, "% 20.9f|%s", tsl, s);
|
||||
else if (config.debugger_show_elapsed_time)
|
||||
daemon_log(LOG_DEBUG, "% 20.9f|%s", tss, s);
|
||||
else
|
||||
daemon_log(LOG_DEBUG, "%s", s);
|
||||
}
|
||||
|
||||
void inform(const char *format, ...) {
|
||||
@@ -664,15 +678,15 @@ uint32_t uatoi(const char *nptr) {
|
||||
return r;
|
||||
}
|
||||
|
||||
|
||||
double flat_vol2attn(double vol, long max_db, long min_db) {
|
||||
double vol_setting = min_db;
|
||||
|
||||
if ((vol <= 0.0) && (vol >= -30.0)) {
|
||||
vol_setting = ((max_db - min_db)*(30.0+vol)/30)+min_db;
|
||||
debug(2,"Linear Volume Setting: %f in range %ld to %ld.",vol_setting,min_db,max_db);
|
||||
vol_setting = ((max_db - min_db) * (30.0 + vol) / 30) + min_db;
|
||||
debug(2, "Linear Volume Setting: %f in range %ld to %ld.", vol_setting, min_db, max_db);
|
||||
} else if (vol != -144.0) {
|
||||
debug(1, "Linear volume request value %f is out of range: should be from 0.0 to -30.0 or -144.0.",
|
||||
debug(1,
|
||||
"Linear volume request value %f is out of range: should be from 0.0 to -30.0 or -144.0.",
|
||||
vol);
|
||||
}
|
||||
return vol_setting;
|
||||
@@ -738,7 +752,8 @@ double vol2attn(double vol, long max_db, long min_db) {
|
||||
vol_setting = min_db; // for safety, return the lowest setting...
|
||||
}
|
||||
// debug(1,"returning an attenuation of %f.",vol_setting);
|
||||
debug(2,"Standard profile Volume Setting for Airplay vol %f: %f in range %ld to %ld.",vol,vol_setting,min_db,max_db);
|
||||
debug(2, "Standard profile Volume Setting for Airplay vol %f: %f in range %ld to %ld.", vol,
|
||||
vol_setting, min_db, max_db);
|
||||
return vol_setting;
|
||||
}
|
||||
|
||||
|
||||
@@ -136,7 +136,9 @@ typedef struct {
|
||||
char *piddir;
|
||||
char *computed_piddir; // the actual pid directory to create, if any
|
||||
|
||||
int logOutputLevel; // log output level
|
||||
int logOutputLevel; // log output level
|
||||
int debugger_show_elapsed_time; // in the debug message, display the time since startup
|
||||
int debugger_show_relative_time; // in the debug message, display the time since the last one
|
||||
int statistics_requested, use_negotiated_latencies;
|
||||
enum playback_mode_type playback_mode;
|
||||
char *cmd_start, *cmd_stop, *cmd_set_volume;
|
||||
@@ -185,7 +187,7 @@ typedef struct {
|
||||
#ifdef HAVE_METADATA_HUB
|
||||
char *cover_art_cache_dir;
|
||||
#endif
|
||||
int disable_resend_requests; //set this to stop resend request being made for missing packets
|
||||
int disable_resend_requests; // set this to stop resend request being made for missing packets
|
||||
|
||||
} shairport_cfg;
|
||||
|
||||
@@ -234,9 +236,11 @@ double flat_vol2attn(double vol, long max_db, long min_db);
|
||||
double vol2attn(double vol, long max_db, long min_db);
|
||||
|
||||
// return a monolithic (always increasing) time in nanoseconds
|
||||
|
||||
uint64_t get_absolute_time_in_fp(void);
|
||||
|
||||
// time at startup for debugging timing
|
||||
uint64_t fp_time_at_startup, fp_time_at_last_debug_message;
|
||||
|
||||
// this is for reading an unsigned 32 bit number, such as an RTP timestamp
|
||||
|
||||
long endianness;
|
||||
|
||||
@@ -301,9 +301,9 @@ void *dacp_monitor_thread_code(void *na) {
|
||||
if (le >= 8) {
|
||||
// here start looking for the contents of the status update
|
||||
if (dacp_tlv_crawl(&sp, &item_size) == 'cmst') { // status
|
||||
// here, we know that we are receiving playerstatusupdates, so set a flag
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.playerstatusupdates_are_received = 1;
|
||||
// here, we know that we are receiving playerstatusupdates, so set a flag
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.playerstatusupdates_are_received = 1;
|
||||
sp -= item_size; // drop down into the array -- don't skip over it
|
||||
le -= 8;
|
||||
char typestring[5];
|
||||
@@ -545,7 +545,7 @@ void *dacp_monitor_thread_code(void *na) {
|
||||
}
|
||||
|
||||
// finished possibly writing to the metadata hub
|
||||
metadata_hub_modify_epilog();
|
||||
metadata_hub_modify_epilog();
|
||||
} else {
|
||||
printf("Status Update not found.\n");
|
||||
}
|
||||
|
||||
+16
-19
@@ -77,33 +77,31 @@ void add_metadata_watcher(metadata_watcher fn, void *userdata) {
|
||||
}
|
||||
|
||||
void metadata_hub_modify_prolog(void) {
|
||||
// always run this before changing an entry or a sequence of entries in the metadata_hub
|
||||
debug(1,"locking metadata hub for writing");
|
||||
// always run this before changing an entry or a sequence of entries in the metadata_hub
|
||||
debug(1, "locking metadata hub for writing");
|
||||
pthread_rwlock_wrlock(&metadata_hub_re_lock);
|
||||
|
||||
}
|
||||
|
||||
void run_metadata_watchers(void) {
|
||||
int i;
|
||||
debug(1,"locking metadata hub for reading");
|
||||
debug(1, "locking metadata hub for reading");
|
||||
pthread_rwlock_rdlock(&metadata_hub_re_lock);
|
||||
for (i = 0; i < number_of_watchers; i++) {
|
||||
if (metadata_store.watchers[i]) {
|
||||
metadata_store.watchers[i](&metadata_store, metadata_store.watchers_data[i]);
|
||||
}
|
||||
}
|
||||
debug(1,"unlocking metadata hub for reading");
|
||||
debug(1, "unlocking metadata hub for reading");
|
||||
pthread_rwlock_unlock(&metadata_hub_re_lock);
|
||||
}
|
||||
|
||||
void metadata_hub_modify_epilog(void) {
|
||||
// always run this after changing an entry or a sequence of entries in the metadata_hub
|
||||
debug(1,"unlocking metadata hub for writing");
|
||||
// always run this after changing an entry or a sequence of entries in the metadata_hub
|
||||
debug(1, "unlocking metadata hub for writing");
|
||||
pthread_rwlock_unlock(&metadata_hub_re_lock);
|
||||
run_metadata_watchers();
|
||||
}
|
||||
|
||||
|
||||
char *metadata_write_image_file(const char *buf, int len) {
|
||||
|
||||
// warning -- this removes all files from the directory apart from this one, if it exists
|
||||
@@ -153,7 +151,7 @@ char *metadata_write_image_file(const char *buf, int len) {
|
||||
debug(1, "Unidentified image type of cover art -- jpg extension used.");
|
||||
ext = jpg;
|
||||
}
|
||||
mode_t oldumask = umask(000);
|
||||
mode_t oldumask = umask(000);
|
||||
int result = mkpath(config.cover_art_cache_dir, 0777);
|
||||
umask(oldumask);
|
||||
if ((result == 0) || (result == -EEXIST)) {
|
||||
@@ -227,10 +225,10 @@ void metadata_hub_process_metadata(uint32_t type, uint32_t code, char *data, uin
|
||||
// metadata coming in from the audio source or from Shairport Sync itself passes through here
|
||||
// this has more information about tags, which might be relevant:
|
||||
// https://code.google.com/p/ytrack/wiki/DMAP
|
||||
|
||||
|
||||
// all the following items of metadata are contained in one metadata packet
|
||||
// they are preseded by an 'ssnc' 'mdst' item and followed by an 'ssnc 'mden' item.
|
||||
|
||||
|
||||
if (type == 'core') {
|
||||
switch (code) {
|
||||
case 'asal':
|
||||
@@ -258,7 +256,7 @@ void metadata_hub_process_metadata(uint32_t type, uint32_t code, char *data, uin
|
||||
case 'ascm':
|
||||
if ((metadata_store.comment == NULL) ||
|
||||
(strncmp(metadata_store.comment, data, length) != 0)) {
|
||||
if (metadata_store.comment)
|
||||
if (metadata_store.comment)
|
||||
free(metadata_store.comment);
|
||||
metadata_store.comment = strndup(data, length);
|
||||
// debug(1, "MH Comment set to: \"%s\"", metadata_store.comment);
|
||||
@@ -354,13 +352,12 @@ void metadata_hub_process_metadata(uint32_t type, uint32_t code, char *data, uin
|
||||
}
|
||||
} else if (type == 'ssnc') {
|
||||
switch (code) {
|
||||
|
||||
|
||||
// ignore the following
|
||||
case 'pcst':
|
||||
case 'pcen':
|
||||
break;
|
||||
|
||||
|
||||
break;
|
||||
|
||||
case 'mdst':
|
||||
debug(1, "MH Metadata stream processing start.");
|
||||
metadata_hub_modify_prolog();
|
||||
@@ -371,12 +368,12 @@ void metadata_hub_process_metadata(uint32_t type, uint32_t code, char *data, uin
|
||||
break;
|
||||
case 'PICT':
|
||||
if (length > 16) {
|
||||
metadata_hub_modify_prolog();
|
||||
debug(1, "MH Picture received, length %u bytes.", length);
|
||||
metadata_hub_modify_prolog();
|
||||
debug(1, "MH Picture received, length %u bytes.", length);
|
||||
if (metadata_store.cover_art_pathname)
|
||||
free(metadata_store.cover_art_pathname);
|
||||
metadata_store.cover_art_pathname = metadata_write_image_file(data, length);
|
||||
metadata_hub_modify_epilog();
|
||||
metadata_hub_modify_epilog();
|
||||
}
|
||||
break;
|
||||
case 'clip':
|
||||
|
||||
+2
-2
@@ -99,7 +99,7 @@ void add_metadata_watcher(metadata_watcher fn, void *userdata);
|
||||
void metadata_hub_init(void);
|
||||
void metadata_hub_process_metadata(uint32_t type, uint32_t code, char *data, uint32_t length);
|
||||
|
||||
// these functions lock and unlock the read-write mutex on the metadata hub and run the watchers afterwards
|
||||
// these functions lock and unlock the read-write mutex on the metadata hub and run the watchers
|
||||
// afterwards
|
||||
void metadata_hub_modify_prolog(void);
|
||||
void metadata_hub_modify_epilog(void);
|
||||
|
||||
|
||||
@@ -816,9 +816,9 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) {
|
||||
|
||||
// say we have started playing here
|
||||
#ifdef HAVE_METADATA_HUB
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_PLAYING;
|
||||
metadata_hub_modify_epilog();
|
||||
metadata_hub_modify_epilog();
|
||||
#endif
|
||||
if (reference_timestamp) { // if we have a reference time
|
||||
// debug(1,"First frame seen with timestamp...");
|
||||
@@ -1106,7 +1106,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) {
|
||||
if (do_wait == 0)
|
||||
if ((conn->ab_synced != 0) && (conn->ab_read == conn->ab_write)) { // the buffer is empty!
|
||||
if (notified_buffer_empty == 0) {
|
||||
debug(2, "Buffers exhausted.");
|
||||
debug(3, "Buffers exhausted.");
|
||||
notified_buffer_empty = 1;
|
||||
}
|
||||
do_wait = 1;
|
||||
@@ -1159,10 +1159,10 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) {
|
||||
seq_t next = seq_sum(conn->ab_read, i);
|
||||
abuf = conn->audio_buffer + BUFIDX(next);
|
||||
if (!abuf->ready) {
|
||||
if (config.disable_resend_requests==0) {
|
||||
rtp_request_resend(next, 1, conn);
|
||||
// debug(1,"Resend %u.",next);
|
||||
conn->resend_requests++;
|
||||
if (config.disable_resend_requests == 0) {
|
||||
rtp_request_resend(next, 1, conn);
|
||||
// debug(1,"Resend %u.",next);
|
||||
conn->resend_requests++;
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -1632,7 +1632,7 @@ static void *player_thread_func(void *arg) {
|
||||
|
||||
player_volume(config.airplay_volume, conn);
|
||||
int64_t frames_to_drop = 0;
|
||||
|
||||
|
||||
while (!conn->player_thread_please_stop) {
|
||||
abuf_t *inframe = buffer_get_frame(conn);
|
||||
if (inframe) {
|
||||
@@ -1659,7 +1659,7 @@ static void *player_thread_func(void *arg) {
|
||||
} else if (frames_to_drop) {
|
||||
// debug(2,"%lld frames to drop.",frames_to_drop);
|
||||
frames_to_drop -= inframe->length;
|
||||
if (frames_to_drop<0)
|
||||
if (frames_to_drop < 0)
|
||||
frames_to_drop = 0;
|
||||
} else {
|
||||
int enable_dither = 0;
|
||||
@@ -1872,7 +1872,7 @@ static void *player_thread_func(void *arg) {
|
||||
config.resyncthreshold * config.output_rate; // number of samples
|
||||
if ((sync_error > 0) && (sync_error > filler_length)) {
|
||||
debug(1, "Large positive sync error: %lld.", sync_error);
|
||||
frames_to_drop = sync_error/conn->output_sample_ratio;
|
||||
frames_to_drop = sync_error / conn->output_sample_ratio;
|
||||
} else if ((sync_error < 0) && ((-sync_error) > filler_length)) {
|
||||
// debug(1, "Large negative sync error: %lld. Inserting silence.", sync_error);
|
||||
size_t silence_length = -sync_error;
|
||||
@@ -2208,8 +2208,6 @@ static void *player_thread_func(void *arg) {
|
||||
|
||||
if (config.output->stop)
|
||||
config.output->stop();
|
||||
usleep(100000); // allow this time to (?) allow the alsa subsystem to finish cleaning up after
|
||||
// itself. 50 ms seems too short
|
||||
|
||||
debug(2, "Shut down audio, control and timing threads");
|
||||
conn->please_stop = 1;
|
||||
@@ -2217,14 +2215,17 @@ static void *player_thread_func(void *arg) {
|
||||
pthread_kill(rtp_control_thread, SIGUSR1);
|
||||
pthread_kill(rtp_timing_thread, SIGUSR1);
|
||||
pthread_join(rtp_timing_thread, NULL);
|
||||
debug(3, "timing thread joined");
|
||||
debug(1, "timing thread joined");
|
||||
pthread_join(rtp_audio_thread, NULL);
|
||||
debug(3, "audio thread joined");
|
||||
debug(1, "audio thread joined");
|
||||
pthread_join(rtp_control_thread, NULL);
|
||||
debug(3, "control thread joined");
|
||||
debug(1, "control thread joined");
|
||||
clear_reference_timestamp(conn);
|
||||
conn->rtp_running = 0;
|
||||
|
||||
usleep(100000); // allow this time to (?) allow the alsa subsystem to finish cleaning up after
|
||||
// itself. 50 ms seems too short
|
||||
|
||||
free_audio_buffers(conn);
|
||||
terminate_decoders(conn);
|
||||
// remove flow control and mutexes
|
||||
@@ -2423,10 +2424,11 @@ void player_volume_without_notification(double airplay_volume, rtsp_conn_info *c
|
||||
if (config.ignore_volume_control == 1)
|
||||
scaled_attenuation = max_db;
|
||||
else if (config.volume_control_profile == VCP_standard)
|
||||
scaled_attenuation = vol2attn(airplay_volume, max_db, min_db);
|
||||
scaled_attenuation = vol2attn(airplay_volume, max_db, min_db);
|
||||
else if (config.volume_control_profile == VCP_flat)
|
||||
scaled_attenuation = flat_vol2attn(airplay_volume, max_db, min_db);
|
||||
else debug(1,"Unrecognised volume control profile");
|
||||
scaled_attenuation = flat_vol2attn(airplay_volume, max_db, min_db);
|
||||
else
|
||||
debug(1, "Unrecognised volume control profile");
|
||||
|
||||
if (hw_range_db) {
|
||||
// if there is a hardware mixer
|
||||
@@ -2509,9 +2511,9 @@ void player_flush(int64_t timestamp, rtsp_conn_info *conn) {
|
||||
#endif
|
||||
|
||||
#ifdef HAVE_METADATA_HUB
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_PAUSED;
|
||||
metadata_hub_modify_epilog();
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_PAUSED;
|
||||
metadata_hub_modify_epilog();
|
||||
#endif
|
||||
}
|
||||
|
||||
@@ -2539,9 +2541,9 @@ int player_play(rtsp_conn_info *conn) {
|
||||
pthread_create(pt, &tattr, player_thread_func, (void *)conn);
|
||||
pthread_attr_destroy(&tattr);
|
||||
#ifdef HAVE_METADATA_HUB
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_PLAYING;
|
||||
metadata_hub_modify_epilog();
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_PLAYING;
|
||||
metadata_hub_modify_epilog();
|
||||
#endif
|
||||
return 0;
|
||||
}
|
||||
@@ -2559,9 +2561,9 @@ void player_stop(rtsp_conn_info *conn) {
|
||||
free(conn->player_thread);
|
||||
conn->player_thread = NULL;
|
||||
#ifdef HAVE_METADATA_HUB
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_STOPPED;
|
||||
metadata_hub_modify_epilog();
|
||||
metadata_hub_modify_prolog();
|
||||
metadata_store.player_state = PS_STOPPED;
|
||||
metadata_hub_modify_epilog();
|
||||
#endif
|
||||
} else {
|
||||
debug(3, "player thread of RTSP conversation %d is already deleted.", conn->connection_number);
|
||||
|
||||
@@ -165,7 +165,7 @@ void *rtp_audio_receiver(void *arg) {
|
||||
warn("Audio receiver -- Unknown RTP packet of type 0x%02X length %d.", type, nread);
|
||||
}
|
||||
|
||||
debug(3, "Audio receiver -- Server RTP thread interrupted. terminating.");
|
||||
debug(2, "Audio receiver -- Server RTP thread interrupted. terminating.");
|
||||
close(conn->audio_socket);
|
||||
|
||||
return NULL;
|
||||
@@ -299,7 +299,7 @@ void *rtp_control_receiver(void *arg) {
|
||||
nread);
|
||||
}
|
||||
|
||||
debug(3, "Control RTP thread interrupted. terminating.");
|
||||
debug(2, "Control RTP thread interrupted. terminating.");
|
||||
close(conn->control_socket);
|
||||
|
||||
return NULL;
|
||||
@@ -365,12 +365,24 @@ void *rtp_timing_sender(void *arg) {
|
||||
debug(1, "Error %d using send-to to the timing socket: \"%s\".", errno, em);
|
||||
}
|
||||
request_number++;
|
||||
|
||||
// this is to deal with the possibility of missing a timing_sender_stop signal.
|
||||
// if the signal came in just before the usleep, then it wouldn't cause the sleep to end.
|
||||
// so, we will wait a maximum time of the wait_interval
|
||||
|
||||
int wait_time;
|
||||
int wait_interval = 20000; // 20 milliseconds
|
||||
|
||||
if (request_number <= 4)
|
||||
usleep(500000);
|
||||
wait_time = 500000;
|
||||
else
|
||||
sleep(3);
|
||||
wait_time = 3000000;
|
||||
while ((wait_time > 0) && (conn->timing_sender_stop == 0)) {
|
||||
usleep(wait_interval);
|
||||
wait_time -= wait_interval;
|
||||
}
|
||||
}
|
||||
debug(3, "rtp_timing_sender thread interrupted. terminating.");
|
||||
debug(2, "rtp_timing_sender thread interrupted. terminating.");
|
||||
return NULL;
|
||||
}
|
||||
|
||||
@@ -591,14 +603,14 @@ void *rtp_timing_receiver(void *arg) {
|
||||
}
|
||||
}
|
||||
|
||||
debug(3, "Timing thread interrupted. terminating.");
|
||||
debug(2, "Timing thread interrupted. terminating.");
|
||||
conn->timing_sender_stop = 1;
|
||||
void *retval;
|
||||
pthread_kill(timer_requester, SIGUSR1);
|
||||
debug(3, "Wait for timer requester to exit.");
|
||||
pthread_join(timer_requester, &retval);
|
||||
debug(3, "Closed and terminated timer requester thread.");
|
||||
debug(3, "Timing RTP thread terminated.");
|
||||
debug(2, "Timing RTP thread terminated.");
|
||||
close(conn->timing_socket);
|
||||
|
||||
return NULL;
|
||||
|
||||
@@ -80,7 +80,7 @@ enum rtsp_read_request_response {
|
||||
rtsp_read_request_response_immediate_shutdown_requested,
|
||||
rtsp_read_request_response_bad_packet,
|
||||
rtsp_read_request_response_channel_closed,
|
||||
rtsp_read_request_response_read_error,
|
||||
rtsp_read_request_response_read_error,
|
||||
rtsp_read_request_response_error
|
||||
};
|
||||
|
||||
@@ -518,7 +518,7 @@ static enum rtsp_read_request_response rtsp_read_request(rtsp_conn_info *conn,
|
||||
continue;
|
||||
char errorstring[1024];
|
||||
strerror_r(errno, (char *)errorstring, sizeof(errorstring));
|
||||
debug(1,"rtsp_read_request_response_read_error %d: \"%s\".",errno,(char *)errorstring);
|
||||
debug(1, "rtsp_read_request_response_read_error %d: \"%s\".", errno, (char *)errorstring);
|
||||
reply = rtsp_read_request_response_read_error;
|
||||
goto shutdown;
|
||||
}
|
||||
@@ -665,7 +665,10 @@ static void msg_write_response(int fd, rtsp_message *resp) {
|
||||
}
|
||||
|
||||
static void handle_record(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) {
|
||||
debug(3, "Connection %d: RECORD", conn->connection_number);
|
||||
debug(2, "Connection %d: RECORD", conn->connection_number);
|
||||
|
||||
player_play(conn); // the thread better be 0
|
||||
|
||||
resp->respcode = 200;
|
||||
// I think this is for telling the client what the absolute minimum latency
|
||||
// actually is,
|
||||
@@ -696,7 +699,7 @@ static void handle_record(rtsp_conn_info *conn, rtsp_message *req, rtsp_message
|
||||
}
|
||||
}
|
||||
}
|
||||
usleep(500000);
|
||||
// usleep(500000);
|
||||
}
|
||||
|
||||
static void handle_options(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) {
|
||||
@@ -708,7 +711,7 @@ static void handle_options(rtsp_conn_info *conn, rtsp_message *req, rtsp_message
|
||||
}
|
||||
|
||||
static void handle_teardown(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) {
|
||||
debug(3, "Connection %d: TEARDOWN", conn->connection_number);
|
||||
debug(2, "Connection %d: TEARDOWN", conn->connection_number);
|
||||
// if (!rtsp_playing())
|
||||
// debug(1, "This RTSP connection thread (%d) doesn't think it's playing, but "
|
||||
// "it's sending a response to teardown anyway",conn->connection_number);
|
||||
@@ -756,7 +759,7 @@ static void handle_flush(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *
|
||||
}
|
||||
|
||||
static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) {
|
||||
debug(3, "Connection %d: SETUP", conn->connection_number);
|
||||
debug(2, "Connection %d: SETUP", conn->connection_number);
|
||||
int cport, tport;
|
||||
int lsport, lcport, ltport;
|
||||
|
||||
@@ -817,8 +820,6 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *
|
||||
strcat(hdr, q); // should unsplice the timing port entry
|
||||
}
|
||||
|
||||
player_play(conn); // the thread better be 0
|
||||
|
||||
char *resphdr = alloca(200);
|
||||
*resphdr = 0;
|
||||
sprintf(resphdr, "RTP/AVP/"
|
||||
@@ -1050,14 +1051,13 @@ void metadata_create(void) {
|
||||
char *path = malloc(pl + 1);
|
||||
snprintf(path, pl + 1, "%s", config.metadata_pipename);
|
||||
|
||||
mode_t oldumask = umask(000);
|
||||
mode_t oldumask = umask(000);
|
||||
|
||||
if (mkfifo(path, 0666) && errno != EEXIST)
|
||||
die("Could not create metadata FIFO %s", path);
|
||||
|
||||
free(path);
|
||||
umask(oldumask);
|
||||
|
||||
}
|
||||
|
||||
void metadata_open(void) {
|
||||
@@ -1418,12 +1418,16 @@ static void handle_set_parameter(rtsp_conn_info *conn, rtsp_message *req, rtsp_m
|
||||
}
|
||||
|
||||
static void handle_announce(rtsp_conn_info *conn, rtsp_message *req, rtsp_message *resp) {
|
||||
debug(3, "Connection %d: ANNOUNCE", conn->connection_number);
|
||||
debug(2, "Connection %d: ANNOUNCE", conn->connection_number);
|
||||
int have_the_player = 0;
|
||||
|
||||
// interrupt session if permitted
|
||||
if (pthread_mutex_trylock(&play_lock) == 0) {
|
||||
have_the_player = 1;
|
||||
} else if ((playing_conn) &&
|
||||
(playing_conn->connection_number == conn->connection_number)) { // duplicate ANNOUNCE
|
||||
debug(1, "Duplicate ANNOUNCE, by the look of it!");
|
||||
have_the_player = 1;
|
||||
} else {
|
||||
int should_wait = 0;
|
||||
|
||||
@@ -1494,12 +1498,12 @@ static void handle_announce(rtsp_conn_info *conn, rtsp_message *req, rtsp_messag
|
||||
|
||||
if (pminlatency) {
|
||||
conn->minimum_latency = atoi(pminlatency);
|
||||
debug(1, "Minimum latency %d specified", conn->minimum_latency);
|
||||
debug(3, "Minimum latency %d specified", conn->minimum_latency);
|
||||
}
|
||||
|
||||
if (pmaxlatency) {
|
||||
conn->maximum_latency = atoi(pmaxlatency);
|
||||
debug(1, "Maximum latency %d specified", conn->maximum_latency);
|
||||
debug(3, "Maximum latency %d specified", conn->maximum_latency);
|
||||
}
|
||||
|
||||
if ((paesiv == NULL) && (prsaaeskey == NULL)) {
|
||||
@@ -1827,7 +1831,7 @@ static void *rtsp_conversation_thread_func(void *pconn) {
|
||||
char *hdr, *auth_nonce = NULL;
|
||||
|
||||
enum rtsp_read_request_response reply;
|
||||
|
||||
|
||||
int rtsp_read_request_attempt_count = 1; // 1 means exit immediately
|
||||
|
||||
while (conn->stop == 0) {
|
||||
@@ -1879,16 +1883,19 @@ static void *rtsp_conversation_thread_func(void *pconn) {
|
||||
int tstop = 0;
|
||||
if (reply == rtsp_read_request_response_immediate_shutdown_requested)
|
||||
tstop = 1;
|
||||
else if ((reply == rtsp_read_request_response_channel_closed) || (reply == rtsp_read_request_response_read_error)) {
|
||||
else if ((reply == rtsp_read_request_response_channel_closed) ||
|
||||
(reply == rtsp_read_request_response_read_error)) {
|
||||
if (conn->player_thread) {
|
||||
rtsp_read_request_attempt_count--;
|
||||
if (rtsp_read_request_attempt_count==0)
|
||||
if (rtsp_read_request_attempt_count == 0)
|
||||
tstop = 1;
|
||||
else {
|
||||
if (reply == rtsp_read_request_response_channel_closed)
|
||||
debug(2,"RTSP channel unexpectedly closed -- will try again %d time(s).",rtsp_read_request_attempt_count);
|
||||
debug(2, "RTSP channel unexpectedly closed -- will try again %d time(s).",
|
||||
rtsp_read_request_attempt_count);
|
||||
if (reply == rtsp_read_request_response_read_error)
|
||||
debug(2,"RTSP channel read error -- will try again %d time(s).",rtsp_read_request_attempt_count);
|
||||
debug(2, "RTSP channel read error -- will try again %d time(s).",
|
||||
rtsp_read_request_attempt_count);
|
||||
usleep(20000);
|
||||
}
|
||||
} else {
|
||||
@@ -1901,7 +1908,7 @@ static void *rtsp_conversation_thread_func(void *pconn) {
|
||||
debug(3, "Synchronously terminate playing thread of RTSP conversation thread %d.",
|
||||
conn->connection_number);
|
||||
if (conn->player_thread)
|
||||
debug(1,"RTSP Channel unexpectedly closed or erred -- closing the session.");
|
||||
debug(1, "RTSP Channel unexpectedly closed or erred -- closing the session.");
|
||||
player_stop(conn);
|
||||
debug(3, "Successful termination of playing thread of RTSP conversation thread %d.",
|
||||
conn->connection_number);
|
||||
|
||||
@@ -150,4 +150,6 @@ diagnostics =
|
||||
// disable_resend_requests = "no"; // set this to yes to stop Shairport Sync from requesting the retransmission of missing packets. Default is "no".
|
||||
// statistics = "no"; // set to "yes" to print statistics in the log
|
||||
// log_verbosity = 0; // "0" means no debug verbosity, "3" is most verbose.
|
||||
// log_show_time_since_startup = "no"; // set this to yes if you want the time since startup in the debug message -- seconds down to nanoseconds
|
||||
// log_show_time_since_last_message = "no"; // set this to yes if you want the time since the last debug message in the debug message -- seconds down to nanoseconds
|
||||
};
|
||||
|
||||
+37
-8
@@ -508,7 +508,8 @@ int parse_options(int argc, char **argv) {
|
||||
|
||||
/* Get the statistics setting. */
|
||||
if (config_lookup_string(config.cfg, "general.statistics", &str)) {
|
||||
warn("The \"general\" \"statistics\" setting is deprecated. Please use the \"diagnostics\" \"statistics\" setting instead.");
|
||||
warn("The \"general\" \"statistics\" setting is deprecated. Please use the \"diagnostics\" "
|
||||
"\"statistics\" setting instead.");
|
||||
if (strcasecmp(str, "no") == 0)
|
||||
config.statistics_requested = 0;
|
||||
else if (strcasecmp(str, "yes") == 0)
|
||||
@@ -541,7 +542,8 @@ int parse_options(int argc, char **argv) {
|
||||
|
||||
/* Get the verbosity setting. */
|
||||
if (config_lookup_int(config.cfg, "general.log_verbosity", &value)) {
|
||||
warn("The \"general\" \"log_verbosity\" setting is deprecated. Please use the \"diagnostics\" \"log_verbosity\" setting instead.");
|
||||
warn("The \"general\" \"log_verbosity\" setting is deprecated. Please use the "
|
||||
"\"diagnostics\" \"log_verbosity\" setting instead.");
|
||||
if ((value >= 0) && (value <= 3))
|
||||
debuglev = value;
|
||||
else
|
||||
@@ -555,11 +557,34 @@ int parse_options(int argc, char **argv) {
|
||||
if ((value >= 0) && (value <= 3))
|
||||
debuglev = value;
|
||||
else
|
||||
die("Invalid diagnostics log_verbosity setting option choice \"%d\". It should be between 0 and 3, "
|
||||
die("Invalid diagnostics log_verbosity setting option choice \"%d\". It should be "
|
||||
"between 0 and 3, "
|
||||
"inclusive.",
|
||||
value);
|
||||
}
|
||||
|
||||
/* Get the show elapsed time in debug messages setting. */
|
||||
if (config_lookup_string(config.cfg, "diagnostics.log_show_time_since_startup", &str)) {
|
||||
if (strcasecmp(str, "no") == 0)
|
||||
config.debugger_show_elapsed_time = 0;
|
||||
else if (strcasecmp(str, "yes") == 0)
|
||||
config.debugger_show_elapsed_time = 1;
|
||||
else
|
||||
die("Invalid diagnostics log_show_time_since_startup option choice \"%s\". It should be "
|
||||
"\"yes\" or \"no\"");
|
||||
}
|
||||
|
||||
/* Get the show relative time in debug messages setting. */
|
||||
if (config_lookup_string(config.cfg, "diagnostics.log_show_time_since_last_message", &str)) {
|
||||
if (strcasecmp(str, "no") == 0)
|
||||
config.debugger_show_relative_time = 0;
|
||||
else if (strcasecmp(str, "yes") == 0)
|
||||
config.debugger_show_relative_time = 1;
|
||||
else
|
||||
die("Invalid diagnostics log_show_time_since_last_message option choice \"%s\". It "
|
||||
"should be \"yes\" or \"no\"");
|
||||
}
|
||||
|
||||
/* Get the statistics setting. */
|
||||
if (config_lookup_string(config.cfg, "diagnostics.statistics", &str)) {
|
||||
if (strcasecmp(str, "no") == 0)
|
||||
@@ -567,10 +592,10 @@ int parse_options(int argc, char **argv) {
|
||||
else if (strcasecmp(str, "yes") == 0)
|
||||
config.statistics_requested = 1;
|
||||
else
|
||||
die("Invalid diagnostics statistics option choice \"%s\". It should be \"yes\" or \"no\"");
|
||||
die("Invalid diagnostics statistics option choice \"%s\". It should be \"yes\" or "
|
||||
"\"no\"");
|
||||
}
|
||||
|
||||
|
||||
/* Get the disable_resend_requests setting. */
|
||||
if (config_lookup_string(config.cfg, "diagnostics.disable_resend_requests", &str)) {
|
||||
config.disable_resend_requests = 0; // this is for legacy -- only set by -t 0
|
||||
@@ -629,7 +654,8 @@ int parse_options(int argc, char **argv) {
|
||||
else if (strcasecmp(str, "flat") == 0)
|
||||
config.volume_control_profile = VCP_flat;
|
||||
else
|
||||
die("Invalid volume_control_profile choice \"%s\". It should be \"standard\" (default) or \"flat\"");
|
||||
die("Invalid volume_control_profile choice \"%s\". It should be \"standard\" (default) "
|
||||
"or \"flat\"");
|
||||
}
|
||||
|
||||
/* Get the interface to listen on, if specified Default is all interfaces */
|
||||
@@ -1065,7 +1091,9 @@ void exit_function() {
|
||||
}
|
||||
|
||||
int main(int argc, char **argv) {
|
||||
|
||||
fp_time_at_startup = get_absolute_time_in_fp();
|
||||
fp_time_at_last_debug_message = fp_time_at_startup;
|
||||
// debug(1,"startup");
|
||||
daemon_set_verbosity(LOG_DEBUG);
|
||||
memset(&config, 0, sizeof(config)); // also clears all strings, BTW
|
||||
atexit(exit_function);
|
||||
@@ -1443,7 +1471,8 @@ int main(int argc, char **argv) {
|
||||
#endif
|
||||
debug(1, "loudness is %d.", config.loudness);
|
||||
debug(1, "loudness reference level is %f", config.loudness_reference_volume_db);
|
||||
debug(1, "disable resend requests is %d -- non-zero means \"yes\"", config.disable_resend_requests);
|
||||
debug(1, "disable resend requests is %d -- non-zero means \"yes\"",
|
||||
config.disable_resend_requests);
|
||||
|
||||
uint8_t ap_md5[16];
|
||||
|
||||
|
||||
Reference in New Issue
Block a user