From 0083d457d8392d63285e41f581547beba5194c8d Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Tue, 8 May 2018 21:14:27 +0100 Subject: [PATCH 01/44] Update RELEASENOTES.md --- RELEASENOTES.md | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index ecc4fbb0..f6d4a919 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,3 +1,8 @@ +Version 3.2d47 +==== +**Bug Fix** +* A very subtle bug that would occasionally cause a loud 80 millisecond buzz when a new track was selected has been located and fixed. Thanks to [mistipen](https://github.com/mistepien) and [artenverho](https://github.com/artenverho) for help with this. + Version 3.2d46 ==== From 8c6e4b8ea4202fdb52c44c2ecc7026ac17b3324f Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Wed, 9 May 2018 09:29:47 +0100 Subject: [PATCH 02/44] Make the UDP sockets blocking rather than non-blocking, but set 2 millisecond limits on the sendto calls. --- rtp.c | 15 ++++++++++++--- 1 file changed, 12 insertions(+), 3 deletions(-) diff --git a/rtp.c b/rtp.c index 40c8bc8b..b0f9e84b 100644 --- a/rtp.c +++ b/rtp.c @@ -469,14 +469,12 @@ void *rtp_timing_sender(void *arg) { if ((config.diagnostic_drop_packet_fraction == 0.0) || (drand48() > config.diagnostic_drop_packet_fraction)) { - if (sendto(conn->timing_socket, &req, sizeof(req), 0, (struct sockaddr *)&conn->rtp_client_timing_socket, msgsize) == -1) { char em[1024]; strerror_r(errno, em, sizeof(em)); debug(1, "Error %d using send-to to the timing socket: \"%s\".", errno, em); } - } else { debug(3, "Timing Sender Thread -- dropping outgoing packet to simulate bad network."); } @@ -808,7 +806,17 @@ static uint16_t bind_port(int ip_family, const char *self_ip_address, uint32_t s struct sockaddr_in *sa = (struct sockaddr_in *)&local; sport = ntohs(sa->sin_port); } - fcntl(local_socket, F_SETFL, O_NONBLOCK); + // fcntl(local_socket, F_SETFL, O_NONBLOCK); + + // don't wait if outputting something will take longer than this time. + struct timeval timeout; + timeout.tv_sec = 0; + timeout.tv_usec = 2000; // two milliseconds + + if (setsockopt(local_socket, SOL_SOCKET, SO_SNDTIMEO, (char *)&timeout, sizeof(timeout)) < 0) + debug(1, "bind_port set output timeout failed."); + // else + // debug(1,"bind_port set output timeout succeeded."); *sock = local_socket; return sport; @@ -995,6 +1003,7 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { } else { conn->rtp_time_of_last_resend_request_error_fp = 0; } + } else { debug(3, "Dropping resend request packet to simulate a bad network. Backing off for 0.5 " "seconds."); From 31d3526713c50ef770fbd97fd5a3db96dfbc46f7 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Wed, 9 May 2018 09:31:42 +0100 Subject: [PATCH 03/44] Make the UDP sockets blocking rather than non-blocking, but set a two millisecond limit on the sendto calls. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 66816c8a..699dba60 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d47], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d48], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From ef4a63d34ebb4c8bfcf6078836c8251c19eca640 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Wed, 9 May 2018 09:34:57 +0100 Subject: [PATCH 04/44] Update RELEASENOTES.md --- RELEASENOTES.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index f6d4a919..4ac70ac1 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,3 +1,9 @@ + +Version 3.2d48 +==== +**Bug Fix** +* A seg fault possibly caused by a dangling pointer has been addressed by making the UDP sockets blocking rather than non-blocking. A two millisecond limit has been put on the sendto calls. + Version 3.2d47 ==== **Bug Fix** From 46fae8feb316b3853fc558ecebac9f5a160e04fc Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Wed, 9 May 2018 17:15:28 +0100 Subject: [PATCH 05/44] Hack alert. If a very large number of frames to flush is calculate -- shome mhistake -- set it to something smaller. --- player.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/player.c b/player.c index 70d6f7a9..b5fbbc4e 100644 --- a/player.c +++ b/player.c @@ -1725,8 +1725,10 @@ static void *player_thread_func(void *arg) { free(silence); } } else if (frames_to_drop) { - if (frames_to_drop > 3 * config.output_rate) - warn("Very large number of frames to drop: %" PRId64 ".", frames_to_drop); + if (frames_to_drop > 3 * config.output_rate) { + warn("Shome mhistake shurely: very large number of frames to drop: %" PRId64 " -- setting it to %" PRId64 ".", frames_to_drop,3 * config.output_rate); + frames_to_drop = 3 * config.output_rate; + } debug(3, "%" PRId64 " frames to drop.", frames_to_drop); frames_to_drop -= inframe->length; if (frames_to_drop < 0) From 7e7bbaf4dac383d95db8ccfb4e1848e350262700 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Wed, 9 May 2018 20:20:54 +0100 Subject: [PATCH 06/44] Change the resend error backoff to one sixteenth of a second -- now can alomst tolerate a 10% failure of packets. --- rtp.c | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/rtp.c b/rtp.c index b0f9e84b..4189d165 100644 --- a/rtp.c +++ b/rtp.c @@ -986,7 +986,7 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { } #endif uint64_t time_of_sending_fp = get_absolute_time_in_fp(); - uint64_t resend_error_backoff_time = (uint64_t)1 << (32 - 1); // half a second + uint64_t resend_error_backoff_time = (uint64_t)1 << (32 - 4); // one sixteenth of a second if ((conn->rtp_time_of_last_resend_request_error_fp == 0) || ((time_of_sending_fp - conn->rtp_time_of_last_resend_request_error_fp) > resend_error_backoff_time)) { @@ -997,7 +997,7 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { char em[1024]; strerror_r(errno, em, sizeof(em)); debug(1, - "Error %d using send-to to an audio socket: \"%s\". Backing off for 0.5 seconds.", + "Error %d using send-to to an audio socket: \"%s\". Backing off for 1/16th of a second.", errno, em); conn->rtp_time_of_last_resend_request_error_fp = time_of_sending_fp; } else { @@ -1005,8 +1005,8 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { } } else { - debug(3, "Dropping resend request packet to simulate a bad network. Backing off for 0.5 " - "seconds."); + debug(3, "Dropping resend request packet to simulate a bad network. Backing off for 1/16th of a " + "second."); conn->rtp_time_of_last_resend_request_error_fp = time_of_sending_fp; } } else { From 23e286e877f1bd2f698266e3b28eb4733408e441 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 10 May 2018 09:05:40 +0100 Subject: [PATCH 07/44] Add a few debug messages to see how far it gets --- player.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/player.c b/player.c index b5fbbc4e..9c6d4604 100644 --- a/player.c +++ b/player.c @@ -1200,6 +1200,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { } while (wait); if (conn->player_thread_please_stop) { + debug(3,"buffer_get_frame exiting due to thread stop request."); pthread_mutex_unlock(&conn->ab_mutex); return 0; } @@ -2272,6 +2273,8 @@ static void *player_thread_func(void *arg) { } } } + + debug(3,"Play thread main loop exited."); if (config.statistics_requested) { int rawSeconds = (int)difftime(time(NULL), playstart); @@ -2288,10 +2291,12 @@ static void *player_thread_func(void *arg) { mdns_dacp_dont_monitor(conn->dapo_private_storage); #endif + debug(3,"Requesting output device to stop."); + if (config.output->stop) config.output->stop(); - debug(2, "Shut down audio, control and timing threads"); + debug(2, "Shutting down audio, control and timing threads"); conn->please_stop = 1; pthread_kill(rtp_audio_thread, SIGUSR1); pthread_kill(rtp_control_thread, SIGUSR1); @@ -2307,6 +2312,8 @@ static void *player_thread_func(void *arg) { // usleep(100000); // allow this time to (?) allow the alsa subsystem to finish cleaning up after // itself. 50 ms seems too short + + debug(3,"Freeing audio buffers and decoders."); free_audio_buffers(conn); terminate_decoders(conn); From 92206b2c1405662aa429dc76644805122b194949 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 10 May 2018 09:24:08 +0100 Subject: [PATCH 08/44] Update configure.ac --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 699dba60..377bd9e5 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d48], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d49], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From 52ecf48fa3eebccf00f1d10f4c6fcbf44d36334a Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 10 May 2018 09:25:31 +0100 Subject: [PATCH 09/44] Update RELEASENOTES.md --- RELEASENOTES.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index 4ac70ac1..2dc3424a 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,4 +1,8 @@ +Version 3.2d49 +==== +* A few extra debugging messages to try to locate where a segfault is occurring. + Version 3.2d48 ==== **Bug Fix** From c43e1d7be7ed276189bbd5f294cd01a1e339319a Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 10 May 2018 09:32:13 +0100 Subject: [PATCH 10/44] Update README.md --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index e65d8ecd..4ee3549d 100644 --- a/README.md +++ b/README.md @@ -2,7 +2,7 @@ Shairport Sync ============= Shairport Sync is an AirPlay audio player – it plays audio streamed from iTunes, iOS, Apple TV and macOS devices and AirPlay sources such as Quicktime Player and [ForkedDaapd](http://ejurgensen.github.io/forked-daapd/), among others. -Audio played by a Shairport Sync-powered device stays synchronised with the source and hence with similar devices playing the same source. In this way, synchronised multi-room audio is possible for suitable players. (Hence the name Shairport Sync, BTW.) +Audio played by a Shairport Sync-powered device stays synchronised with the source and hence with similar devices playing the same source. In this way, synchronised multi-room audio is possible for players such as iTunes. Shairport Sync does not support multi-room audio for iOS devices. Shairport Sync runs on Linux and FreeBSD. It does not support AirPlay video or photo streaming. From d805ce914e3d6c65897e97276a9299c1d5ebd386 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 11 May 2018 10:56:16 +0100 Subject: [PATCH 11/44] Make some essentially cosmetic changes to return memory when the program exits. The program never exits, but it's good for valgrind. --- mdns_avahi.c | 12 ++++++++++-- rtsp.c | 17 ++++++++++++----- shairport.c | 35 ++++++++++++++++++++++------------- 3 files changed, 44 insertions(+), 20 deletions(-) diff --git a/mdns_avahi.c b/mdns_avahi.c index 6756c1ea..b1085bb7 100644 --- a/mdns_avahi.c +++ b/mdns_avahi.c @@ -364,9 +364,17 @@ static int avahi_register(char *srvname, int srvport) { static void avahi_unregister(void) { debug(1, "avahi: avahi_unregister."); - if (tpoll) + if (tpoll) { avahi_threaded_poll_stop(tpoll); - tpoll = NULL; + + if (client) { + avahi_client_free(client); + client = NULL; + }; + + avahi_threaded_poll_free(tpoll); + tpoll = NULL; + } if (service_name) free(service_name); diff --git a/rtsp.c b/rtsp.c index 0fb11ce9..0efa2883 100644 --- a/rtsp.c +++ b/rtsp.c @@ -2082,14 +2082,15 @@ void rtsp_listen_loop(void) { } mdns_register(); + // printf("Listening for connections."); // shairport_startup_complete(); int acceptfd; struct timeval tv; - while (1) { - tv.tv_sec = 300; + do { + tv.tv_sec = 60; tv.tv_usec = 0; for (i = 0; i < nsock; i++) @@ -2182,7 +2183,13 @@ void rtsp_listen_loop(void) { conn->running = 1; // this must happen before the thread is tracked track_thread(conn); } - } - perror("select"); - die("fell out of the RTSP select loop"); + } while (1); + + mdns_unregister(); + + if (sockfd) + free(sockfd); + + //perror("select"); + //die("fell out of the RTSP select loop"); } diff --git a/shairport.c b/shairport.c index 13e6bff8..1d6407ab 100644 --- a/shairport.c +++ b/shairport.c @@ -274,6 +274,8 @@ int parse_options(int argc, char **argv) { optind = j; optCon = poptGetContext(NULL, optind, (const char **)argv, optionsTable, 0); + if (optCon==NULL) + die("Can not get a secondary popt context."); poptSetOtherOptionHelp(optCon, "[OPTIONS]* "); /* Now do options processing just to get a debug level */ @@ -318,6 +320,8 @@ int parse_options(int argc, char **argv) { die("%s: %s", poptBadOption(optCon, POPT_BADOPTION_NOALIAS), poptStrerror(c)); } + poptFreeContext(optCon); + if ((daemonisewith) && (daemonisewithout)) die("Select either daemonize_with_pid_file or daemonize_without_pid_file -- you have selected " "both!"); @@ -888,6 +892,8 @@ int parse_options(int argc, char **argv) { optind = j; optCon = poptGetContext(NULL, optind, (const char **)argv, optionsTable, 0); + if (optCon==NULL) + die("Can not get a popt context."); poptSetOtherOptionHelp(optCon, "[OPTIONS]* "); /* Now do options processing, get portname */ @@ -935,6 +941,7 @@ int parse_options(int argc, char **argv) { die("%s: %s", poptBadOption(optCon, POPT_BADOPTION_NOALIAS), poptStrerror(c)); } + poptFreeContext(optCon); #ifdef CONFIG_METADATA if ((config.metadata_enabled == 1) && (config.metadata_pipename == NULL)) config.metadata_pipename = strdup("/tmp/shairport-sync-metadata"); @@ -956,6 +963,10 @@ int parse_options(int argc, char **argv) { char hostname[100]; gethostname(hostname, 100); char *i1 = str_replace(raw_service_name, "%h", hostname); + if (raw_service_name) { + free(raw_service_name); + raw_service_name = NULL; + } if ((hostname[0] >= 'a') && (hostname[0] <= 'z')) hostname[0] = hostname[0] - 0x20; // convert a lowercase first letter into a capital letter char *i2 = str_replace(i1, "%H", hostname); @@ -1041,13 +1052,15 @@ void shairport_startup_complete(void) { } } -const char *pid_file_proc(void) { - - char fn[8192]; - snprintf(fn, sizeof(fn), "%s/%s.pid", config.computed_piddir, - daemon_pid_file_ident ? daemon_pid_file_ident : "unknown"); - // debug(1,"fn \"%s\".",fn); - return strdup(fn); +const char *pid_file_proc(char* fn,size_t max_length) { + if (fn) { + snprintf(fn, max_length, "%s/%s.pid", config.computed_piddir, + daemon_pid_file_ident ? daemon_pid_file_ident : "unknown"); + // debug(1,"fn \"%s\".",fn); + } else { + debug(1,"the sise of the buffer for the PID file path is zero."); + } + return fn; } void exit_function() { @@ -1168,11 +1181,6 @@ int main(int argc, char **argv) { return 1; } - // Point to a function to help locate where the PID file will go - // We always use this function because the default location - // is unsatisfactory. By default we want to use /var/run/shairport-sync/. - daemon_pid_file_proc = pid_file_proc; - /* Set indentification string for the daemon for both syslog and PID file */ daemon_pid_file_ident = daemon_log_ident = daemon_ident_from_argv0(argv[0]); @@ -1366,10 +1374,11 @@ int main(int argc, char **argv) { debug(1, "Can't print the version information!"); } + char pid_file_path_string[4096] = "\0"; /* Print out options */ debug(1, "statistics_requester status is %d.", config.statistics_requested); debug(1, "daemon status is %d.", config.daemonise); - debug(1, "deamon pid file is \"%s\".", pid_file_proc()); + debug(1, "deamon pid file is \"%s\".", pid_file_proc(pid_file_path_string,4096)); 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); From f8822ddf9834c44c8350fa87f2e36ef9e10efd7f Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 11 May 2018 11:24:29 +0100 Subject: [PATCH 12/44] Update shairport-sync.conf --- scripts/shairport-sync.conf | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/scripts/shairport-sync.conf b/scripts/shairport-sync.conf index 417aeb38..ae2fe4e5 100644 --- a/scripts/shairport-sync.conf +++ b/scripts/shairport-sync.conf @@ -48,7 +48,7 @@ general = // as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session". }; -// Advanced parameters for controlling how a Shairport Sync runs +// Advanced parameters for controlling how Shairport Sync runs a play session sessioncontrol = { // run_this_before_play_begins = "/full/path/to/application and args"; // make sure the application has executable permission. If it's a script, include the shebang (#!/bin/...) on the first line @@ -56,6 +56,7 @@ sessioncontrol = // wait_for_completion = "no"; // set to "yes" to get Shairport Sync to wait until the "run_this..." applications have terminated before continuing // allow_session_interruption = "no"; // set to "yes" to allow another device to interrupt Shairport Sync while it's playing from an existing audio source // session_timeout = 120; // wait for this number of seconds after a source disappears before terminating the session and becoming available again. +// fixed_latency = 88200; // set this between 441 and 110250 to override the latency requested by the AirPlay source. }; // Back End Settings From 1a0b59e8ee8d8005034700c7ed625cd4cf7de8f8 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 11 May 2018 11:44:50 +0100 Subject: [PATCH 13/44] Update shairport-sync.conf --- scripts/shairport-sync.conf | 1 - 1 file changed, 1 deletion(-) diff --git a/scripts/shairport-sync.conf b/scripts/shairport-sync.conf index ae2fe4e5..7c654836 100644 --- a/scripts/shairport-sync.conf +++ b/scripts/shairport-sync.conf @@ -56,7 +56,6 @@ sessioncontrol = // wait_for_completion = "no"; // set to "yes" to get Shairport Sync to wait until the "run_this..." applications have terminated before continuing // allow_session_interruption = "no"; // set to "yes" to allow another device to interrupt Shairport Sync while it's playing from an existing audio source // session_timeout = 120; // wait for this number of seconds after a source disappears before terminating the session and becoming available again. -// fixed_latency = 88200; // set this between 441 and 110250 to override the latency requested by the AirPlay source. }; // Back End Settings From 803cbf7d1c8befa88679e361caddace2f899e9c7 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 11 May 2018 12:23:17 +0100 Subject: [PATCH 14/44] Add limit checks to the (deprecated) -L fixed latency setting. --- shairport.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/shairport.c b/shairport.c index 1d6407ab..fcb7629c 100644 --- a/shairport.c +++ b/shairport.c @@ -1358,10 +1358,12 @@ int main(int argc, char **argv) { // audio_backend_latency_offset instead. if (config.userSuppliedLatency) { - inform("The default latency setting is deprecated, as Shairport Sync can now get the correct " + inform("The fixed latency setting is deprecated, as Shairport Sync can now get the correct " "latency from the source."); inform("Please remove this setting and use the relevant audio_backend_latency_offset setting, " "if necessary, to compensate for delays elsewhere."); + if ((config.userSuppliedLatency!=0) && ((config.userSuppliedLatency<4410) || (config.userSuppliedLatency>154350))) + die("An out-of-range fixed latency has been specified. It must be between 4,410 and 154,350."); } /* print out version */ From 418b1ba7c724b74ecba0d41033138f5bdf097c6a Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sat, 12 May 2018 15:10:27 +0100 Subject: [PATCH 15/44] Add a read-write mutex to protect a player thread when it's being created or deleted; make player_flush get a read lock to get access. --- player.c | 91 ++++++++++++++++++++++++++++++++++++-------------------- player.h | 3 +- rtsp.c | 23 ++++++++++---- 3 files changed, 78 insertions(+), 39 deletions(-) diff --git a/player.c b/player.c index 9c6d4604..062e63b5 100644 --- a/player.c +++ b/player.c @@ -749,6 +749,8 @@ static inline void process_sample(int32_t sample, char **outp, enum sps_format_t } // get the next frame, when available. return 0 if underrun/stream reset. +// remember that this function will be running in the audio receiver thread. + static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { // int16_t buf_fill; uint64_t local_time_now; @@ -1200,7 +1202,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { } while (wait); if (conn->player_thread_please_stop) { - debug(3,"buffer_get_frame exiting due to thread stop request."); + debug(3, "buffer_get_frame exiting due to thread stop request."); pthread_mutex_unlock(&conn->ab_mutex); return 0; } @@ -1397,26 +1399,11 @@ typedef struct stats { // statistics for running averages static void *player_thread_func(void *arg) { + // note, the thread will be started up with the player_thread_lock locked. You must release it + // quickly. + rtsp_conn_info *conn = (rtsp_conn_info *)arg; - conn->please_stop = 0; - conn->packet_count = 0; - conn->previous_random_number = 0; - conn->input_bytes_per_frame = 4; - conn->player_thread_please_stop = 0; - conn->decoder_in_use = 0; - conn->ab_buffering = 1; - conn->ab_synced = 0; - conn->first_packet_timestamp = 0; - conn->flush_requested = 0; - conn->fix_volume = 0x10000; - - if (conn->latency == 0) { - debug(3, "No latency has (yet) been specified. Setting 88,200 (2 seconds) frames " - "as a default."); - conn->latency = 88200; - } - int rc = pthread_mutex_init(&conn->ab_mutex, NULL); if (rc) debug(1, "Error initialising ab_mutex."); @@ -1438,6 +1425,29 @@ static void *player_thread_func(void *arg) { #endif if (rc) debug(1, "Error initialising flowcontrol condition variable."); + + pthread_rwlock_unlock(&conn->player_thread_lock); + + // it's safe now + + conn->please_stop = 0; + conn->packet_count = 0; + conn->previous_random_number = 0; + conn->input_bytes_per_frame = 4; + conn->player_thread_please_stop = 0; + conn->decoder_in_use = 0; + conn->ab_buffering = 1; + conn->ab_synced = 0; + conn->first_packet_timestamp = 0; + conn->flush_requested = 0; + conn->fix_volume = 0x10000; + + if (conn->latency == 0) { + debug(3, "No latency has (yet) been specified. Setting 88,200 (2 seconds) frames " + "as a default."); + conn->latency = 88200; + } + config.output->start(config.output_rate, config.output_format); init_decoder((int32_t *)&conn->stream.fmtp, @@ -1727,7 +1737,9 @@ static void *player_thread_func(void *arg) { } } else if (frames_to_drop) { if (frames_to_drop > 3 * config.output_rate) { - warn("Shome mhistake shurely: very large number of frames to drop: %" PRId64 " -- setting it to %" PRId64 ".", frames_to_drop,3 * config.output_rate); + warn("Shome mhistake shurely: very large number of frames to drop: %" PRId64 + " -- setting it to %" PRId64 ".", + frames_to_drop, 3 * config.output_rate); frames_to_drop = 3 * config.output_rate; } debug(3, "%" PRId64 " frames to drop.", frames_to_drop); @@ -2273,8 +2285,8 @@ static void *player_thread_func(void *arg) { } } } - - debug(3,"Play thread main loop exited."); + + debug(3, "Play thread main loop exited."); if (config.statistics_requested) { int rawSeconds = (int)difftime(time(NULL), playstart); @@ -2291,7 +2303,7 @@ static void *player_thread_func(void *arg) { mdns_dacp_dont_monitor(conn->dapo_private_storage); #endif - debug(3,"Requesting output device to stop."); + debug(3, "Requesting output device to stop."); if (config.output->stop) config.output->stop(); @@ -2312,8 +2324,8 @@ static void *player_thread_func(void *arg) { // usleep(100000); // allow this time to (?) allow the alsa subsystem to finish cleaning up after // itself. 50 ms seems too short - - debug(3,"Freeing audio buffers and decoders."); + + debug(3, "Freeing audio buffers and decoders."); free_audio_buffers(conn); terminate_decoders(conn); @@ -2582,11 +2594,15 @@ void player_volume(double airplay_volume, rtsp_conn_info *conn) { void player_flush(int64_t timestamp, rtsp_conn_info *conn) { debug(3, "Flush requested up to %u. It seems as if 0 is special.", timestamp); - pthread_mutex_lock(&conn->flush_mutex); - conn->flush_requested = 1; - // if (timestamp!=0) - conn->flush_rtp_timestamp = timestamp; // flush all packets up to (and including?) this - pthread_mutex_unlock(&conn->flush_mutex); + pthread_rwlock_rdlock(&conn->player_thread_lock); + if (conn->player_thread != NULL) { + pthread_mutex_lock(&conn->flush_mutex); + conn->flush_requested = 1; + // if (timestamp!=0) + conn->flush_rtp_timestamp = timestamp; // flush all packets up to (and including?) this + pthread_mutex_unlock(&conn->flush_mutex); + } + pthread_rwlock_unlock(&conn->player_thread_lock); conn->play_segment_reference_frame = 0; conn->play_number_after_flush = 0; #ifdef CONFIG_METADATA @@ -2611,6 +2627,7 @@ int player_play(rtsp_conn_info *conn) { debug(2, "pbeg"); send_ssnc_metadata('pbeg', NULL, 0, 1); #endif + pthread_rwlock_wrlock(&conn->player_thread_lock); pthread_t *pt = malloc(sizeof(pthread_t)); if (pt == NULL) die("Couldn't allocate space for pthread_t"); @@ -2621,25 +2638,33 @@ int player_play(rtsp_conn_info *conn) { int rc = pthread_attr_setstacksize(&tattr, size); if (rc) debug(1, "Error setting stack size for player_thread: %s", strerror(errno)); + + // hack alert -- the player thread itself releases the player_thread_lock rwlock as soon as it's + // finished initialising. pthread_create(pt, &tattr, player_thread_func, (void *)conn); pthread_attr_destroy(&tattr); return 0; } -void player_stop(rtsp_conn_info *conn) { +int player_stop(rtsp_conn_info *conn) { + pthread_rwlock_wrlock(&conn->player_thread_lock); if (conn->player_thread) { conn->player_thread_please_stop = 1; pthread_cond_signal(&conn->flowcontrol); // tell it to give up pthread_kill(*conn->player_thread, SIGUSR1); pthread_join(*conn->player_thread, NULL); + free(conn->player_thread); + conn->player_thread = NULL; + pthread_rwlock_unlock(&conn->player_thread_lock); #ifdef CONFIG_METADATA debug(2, "pend"); send_ssnc_metadata('pend', NULL, 0, 1); #endif command_stop(); - free(conn->player_thread); - conn->player_thread = NULL; + return 0; } else { + pthread_rwlock_unlock(&conn->player_thread_lock); debug(3, "player thread of RTSP conversation %d is already deleted.", conn->connection_number); + return -1; } } diff --git a/player.h b/player.h index 7ede6e9f..e6339477 100644 --- a/player.h +++ b/player.h @@ -74,6 +74,7 @@ typedef struct { // pthread_t *ptp; pthread_t *player_thread; + pthread_rwlock_t player_thread_lock; // used to control access by "outsiders" abuf_t audio_buffer[BUFFER_FRAMES]; int max_frames_per_packet, input_num_channels, input_bit_depth, input_rate; @@ -191,7 +192,7 @@ typedef struct { } rtsp_conn_info; int player_play(rtsp_conn_info *conn); -void player_stop(rtsp_conn_info *conn); +int player_stop(rtsp_conn_info *conn); void player_volume(double f, rtsp_conn_info *conn); void player_volume_without_notification(double f, rtsp_conn_info *conn); diff --git a/rtsp.c b/rtsp.c index 0efa2883..a524428f 100644 --- a/rtsp.c +++ b/rtsp.c @@ -1861,6 +1861,12 @@ authenticate: static void *rtsp_conversation_thread_func(void *pconn) { rtsp_conn_info *conn = pconn; + // create the player thread lock. + int rwli = pthread_rwlock_init(&conn->player_thread_lock, NULL); + if (rwli != 0) + die("Error %d initialising player_thread_lock for conversation thread %d.", rwli, + conn->connection_number); + rtp_initialise(conn); rtsp_message *req, *resp; @@ -1943,6 +1949,7 @@ static void *rtsp_conversation_thread_func(void *pconn) { if (tstop) { 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 a serious error occured -- closing the " "player thread."); @@ -1968,6 +1975,13 @@ static void *rtsp_conversation_thread_func(void *pconn) { debug(2, "RTSP conversation thread %d terminated.", conn->connection_number); // please_shutdown = 0; conn->running = 0; + + // release the player_thread_lock + int rwld = pthread_rwlock_destroy(&conn->player_thread_lock); + if (rwld) + debug(1, "Error %d destroying player_thread_lock for conversation thread %d.", rwld, + conn->connection_number); + return NULL; } @@ -2082,7 +2096,6 @@ void rtsp_listen_loop(void) { } mdns_register(); - // printf("Listening for connections."); // shairport_startup_complete(); @@ -2184,12 +2197,12 @@ void rtsp_listen_loop(void) { track_thread(conn); } } while (1); - + mdns_unregister(); - + if (sockfd) free(sockfd); - //perror("select"); - //die("fell out of the RTSP select loop"); + // perror("select"); + // die("fell out of the RTSP select loop"); } From b6fcabca0d829a2b9ea0f912a2a7b9ac18748406 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sat, 12 May 2018 15:35:51 +0100 Subject: [PATCH 16/44] Add a read-write mutex to protect a player thread when it's being created or deleted; make player_put_packet get a read lock. --- player.c | 250 ++++++++++++++++++++++++++++--------------------------- 1 file changed, 128 insertions(+), 122 deletions(-) diff --git a/player.c b/player.c index 062e63b5..1950c80b 100644 --- a/player.c +++ b/player.c @@ -464,147 +464,155 @@ static void free_audio_buffers(rtsp_conn_info *conn) { void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp, uint8_t *data, int len, rtsp_conn_info *conn) { + pthread_rwlock_rdlock(&conn->player_thread_lock); + if (conn->player_thread != NULL) { - // all timestamps are done at the output rate - // the "actual_timestamp" is the one that comes in the packet, and is carried over for debugging - // and checking only. + // all timestamps are done at the output rate + // the "actual_timestamp" is the one that comes in the packet, and is carried over for debugging + // and checking only. - int64_t ltimestamp = timestamp * conn->output_sample_ratio; + int64_t ltimestamp = timestamp * conn->output_sample_ratio; - // ignore a request to flush that has been made before the first packet... - if (conn->packet_count == 0) { - pthread_mutex_lock(&conn->flush_mutex); - conn->flush_requested = 0; - conn->flush_rtp_timestamp = 0; - pthread_mutex_unlock(&conn->flush_mutex); - } + // ignore a request to flush that has been made before the first packet... + if (conn->packet_count == 0) { + pthread_mutex_lock(&conn->flush_mutex); + conn->flush_requested = 0; + conn->flush_rtp_timestamp = 0; + pthread_mutex_unlock(&conn->flush_mutex); + } - pthread_mutex_lock(&conn->ab_mutex); - conn->packet_count++; - conn->time_of_last_audio_packet = get_absolute_time_in_fp(); - if (conn->connection_state_to_output) { // if we are supposed to be processing these packets + pthread_mutex_lock(&conn->ab_mutex); + conn->packet_count++; + conn->time_of_last_audio_packet = get_absolute_time_in_fp(); + if (conn->connection_state_to_output) { // if we are supposed to be processing these packets - // if (flush_rtp_timestamp != 0) - // debug(1,"Flush_rtp_timestamp is %u",flush_rtp_timestamp); + // if (flush_rtp_timestamp != 0) + // debug(1,"Flush_rtp_timestamp is %u",flush_rtp_timestamp); - if ((conn->flush_rtp_timestamp != 0) && (ltimestamp <= conn->flush_rtp_timestamp)) { - debug(3, - "Dropping flushed packet in player_put_packet, seqno %u, timestamp %lld, flushing to " - "timestamp: %lld.", - seqno, ltimestamp, conn->flush_rtp_timestamp); - } else { - if ((conn->flush_rtp_timestamp != 0x0) && - (ltimestamp > conn->flush_rtp_timestamp)) // if we have gone past the flush boundary time - conn->flush_rtp_timestamp = 0x0; + if ((conn->flush_rtp_timestamp != 0) && (ltimestamp <= conn->flush_rtp_timestamp)) { + debug(3, + "Dropping flushed packet in player_put_packet, seqno %u, timestamp %lld, flushing to " + "timestamp: %lld.", + seqno, ltimestamp, conn->flush_rtp_timestamp); + } else { + if ((conn->flush_rtp_timestamp != 0x0) && + (ltimestamp > + conn->flush_rtp_timestamp)) // if we have gone past the flush boundary time + conn->flush_rtp_timestamp = 0x0; - abuf_t *abuf = 0; + abuf_t *abuf = 0; - if (!conn->ab_synced) { - debug(3, "syncing to seqno %u.", seqno); - conn->ab_write = seqno; - conn->ab_read = seqno; - conn->ab_synced = 1; - } + if (!conn->ab_synced) { + debug(3, "syncing to seqno %u.", seqno); + conn->ab_write = seqno; + conn->ab_read = seqno; + conn->ab_synced = 1; + } - // here, we should check for missing frames - if (!conn->ab_buffering) { - int j; - for (j = 1; j <= 8; j++) { - // check j times, after a short period of has elapsed, assuming 352 frames per packet - int back_step = (((250 * 44100) / 352) / 1000) * (j); // approx 250 ms intervals - int k; - for (k = -2; k <= 2; k++) { - if (back_step < - seq_diff(conn->ab_read, conn->ab_write, - conn->ab_read)) { // if it's within the range of frames in use... - int item_to_check = (conn->ab_write - back_step) & 0xffff; - seq_t next = item_to_check; - abuf_t *check_buf = conn->audio_buffer + BUFIDX(next); - if ((!check_buf->ready) && - (check_buf->resend_level < - j)) { // prevent multiple requests from the same level of lookback - check_buf->resend_level = j; - if (config.disable_resend_requests == 0) { - rtp_request_resend(next, 1, conn); - if (j >= 6) - debug(2, "Resend request level #%d for packet %u in range %u to %u.", j, next, - conn->ab_read, conn->ab_write); - conn->resend_requests++; + // here, we should check for missing frames + if (!conn->ab_buffering) { + int j; + for (j = 1; j <= 8; j++) { + // check j times, after a short period of has elapsed, assuming 352 frames per packet + int back_step = (((250 * 44100) / 352) / 1000) * (j); // approx 250 ms intervals + int k; + for (k = -2; k <= 2; k++) { + if (back_step < + seq_diff(conn->ab_read, conn->ab_write, + conn->ab_read)) { // if it's within the range of frames in use... + int item_to_check = (conn->ab_write - back_step) & 0xffff; + seq_t next = item_to_check; + abuf_t *check_buf = conn->audio_buffer + BUFIDX(next); + if ((!check_buf->ready) && + (check_buf->resend_level < + j)) { // prevent multiple requests from the same level of lookback + check_buf->resend_level = j; + if (config.disable_resend_requests == 0) { + rtp_request_resend(next, 1, conn); + if (j >= 6) + debug(2, "Resend request level #%d for packet %u in range %u to %u.", j, next, + conn->ab_read, conn->ab_write); + conn->resend_requests++; + } } } } } } - } - if (conn->ab_write == seqno) { // expected packet - abuf = conn->audio_buffer + BUFIDX(seqno); - conn->ab_write = SUCCESSOR(seqno); - } else if (seq_order(conn->ab_write, seqno, conn->ab_read)) { // newer than expected - // if (ORDINATE(seqno)>(BUFFER_FRAMES*7)/8) - // debug(1,"An interval of %u frames has opened, with ab_read: %u, ab_write: %u and seqno: - // %u.",seq_diff(ab_read,seqno),ab_read,ab_write,seqno); - int32_t gap = seq_diff(conn->ab_write, seqno, conn->ab_read); - if (gap <= 0) - debug(1, "Unexpected gap size: %d.", gap); - int i; - for (i = 0; i < gap; i++) { - abuf = conn->audio_buffer + BUFIDX(seq_sum(conn->ab_write, i)); - abuf->ready = 0; // to be sure, to be sure - abuf->resend_level = 0; - abuf->timestamp = 0; - abuf->given_timestamp = 0; - abuf->sequence_number = 0; + if (conn->ab_write == seqno) { // expected packet + abuf = conn->audio_buffer + BUFIDX(seqno); + conn->ab_write = SUCCESSOR(seqno); + } else if (seq_order(conn->ab_write, seqno, conn->ab_read)) { // newer than expected + // if (ORDINATE(seqno)>(BUFFER_FRAMES*7)/8) + // debug(1,"An interval of %u frames has opened, with ab_read: %u, ab_write: %u and seqno: + // %u.",seq_diff(ab_read,seqno),ab_read,ab_write,seqno); + int32_t gap = seq_diff(conn->ab_write, seqno, conn->ab_read); + if (gap <= 0) + debug(1, "Unexpected gap size: %d.", gap); + int i; + for (i = 0; i < gap; i++) { + abuf = conn->audio_buffer + BUFIDX(seq_sum(conn->ab_write, i)); + abuf->ready = 0; // to be sure, to be sure + abuf->resend_level = 0; + abuf->timestamp = 0; + abuf->given_timestamp = 0; + abuf->sequence_number = 0; + } + // debug(1,"N %d s %u.",seq_diff(ab_write,PREDECESSOR(seqno))+1,ab_write); + abuf = conn->audio_buffer + BUFIDX(seqno); + // rtp_request_resend(ab_write, gap); + // resend_requests++; + conn->ab_write = SUCCESSOR(seqno); + } else if (seq_order(conn->ab_read, seqno, conn->ab_read)) { // late but not yet played + conn->late_packets++; + abuf = conn->audio_buffer + BUFIDX(seqno); + /* + if (abuf->ready) + debug(1,"Late apparently duplicate packet received that is %d packets + late.",seq_diff(seqno, conn->ab_write, conn->ab_read)); + else + debug(1,"Late packet received that is %d packets late.",seq_diff(seqno, + conn->ab_write, conn->ab_read)); + */ + } else { // too late. + + // debug(1,"Too late packet received that is %d packets late.",seq_diff(seqno, + // conn->ab_write, conn->ab_read)); + conn->too_late_packets++; } - // debug(1,"N %d s %u.",seq_diff(ab_write,PREDECESSOR(seqno))+1,ab_write); - abuf = conn->audio_buffer + BUFIDX(seqno); - // rtp_request_resend(ab_write, gap); - // resend_requests++; - conn->ab_write = SUCCESSOR(seqno); - } else if (seq_order(conn->ab_read, seqno, conn->ab_read)) { // late but not yet played - conn->late_packets++; - abuf = conn->audio_buffer + BUFIDX(seqno); - /* - if (abuf->ready) - debug(1,"Late apparently duplicate packet received that is %d packets - late.",seq_diff(seqno, conn->ab_write, conn->ab_read)); - else - debug(1,"Late packet received that is %d packets late.",seq_diff(seqno, - conn->ab_write, conn->ab_read)); - */ - } else { // too late. + // pthread_mutex_unlock(&ab_mutex); - // debug(1,"Too late packet received that is %d packets late.",seq_diff(seqno, - // conn->ab_write, conn->ab_read)); - conn->too_late_packets++; - } - // pthread_mutex_unlock(&ab_mutex); - - if (abuf) { - int datalen = conn->max_frames_per_packet; - if (alac_decode(abuf->data, &datalen, data, len, conn) == 0) { - abuf->ready = 1; - abuf->length = datalen; - abuf->timestamp = ltimestamp; - abuf->given_timestamp = actual_timestamp; - abuf->sequence_number = seqno; - } else { - debug(1, "Bad audio packet detected and discarded."); - abuf->ready = 0; - abuf->resend_level = 0; - abuf->timestamp = 0; - abuf->given_timestamp = 0; - abuf->sequence_number = 0; + if (abuf) { + int datalen = conn->max_frames_per_packet; + if (alac_decode(abuf->data, &datalen, data, len, conn) == 0) { + abuf->ready = 1; + abuf->length = datalen; + abuf->timestamp = ltimestamp; + abuf->given_timestamp = actual_timestamp; + abuf->sequence_number = seqno; + } else { + debug(1, "Bad audio packet detected and discarded."); + abuf->ready = 0; + abuf->resend_level = 0; + abuf->timestamp = 0; + abuf->given_timestamp = 0; + abuf->sequence_number = 0; + } } - } - // pthread_mutex_lock(&ab_mutex); + // pthread_mutex_lock(&ab_mutex); + } + int rc = pthread_cond_signal(&conn->flowcontrol); + if (rc) + debug(1, "Error signalling flowcontrol."); } - int rc = pthread_cond_signal(&conn->flowcontrol); - if (rc) - debug(1, "Error signalling flowcontrol."); + pthread_mutex_unlock(&conn->ab_mutex); + } else { + debug(1, + "No player thread while adding a player_put_packet calle was made -- packet discarded."); } - pthread_mutex_unlock(&conn->ab_mutex); + pthread_rwlock_unlock(&conn->player_thread_lock); } int32_t rand_in_range(int32_t exclusive_range_limit) { @@ -749,8 +757,6 @@ static inline void process_sample(int32_t sample, char **outp, enum sps_format_t } // get the next frame, when available. return 0 if underrun/stream reset. -// remember that this function will be running in the audio receiver thread. - static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { // int16_t buf_fill; uint64_t local_time_now; From 8845c60397adef8309c86b56d1bd16eefe99329d Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sat, 12 May 2018 15:36:56 +0100 Subject: [PATCH 17/44] Add a read-write mutex to protect a player thread when it's being created or deleted; make external accessors get a read lock. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 377bd9e5..da112979 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d49], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d50], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From 6f8c9e9aa24ed6f8b6634bcc2f5f553e84c8abda Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sat, 12 May 2018 15:57:23 +0100 Subject: [PATCH 18/44] split player_flush into two -- make do_flush for internal use, player_flush for external use. --- player.c | 30 +++++++++++++++++++----------- 1 file changed, 19 insertions(+), 11 deletions(-) diff --git a/player.c b/player.c index 1950c80b..1284a74d 100644 --- a/player.c +++ b/player.c @@ -106,6 +106,8 @@ // static abuf_t audio_buffer[BUFFER_FRAMES]; #define BUFIDX(seqno) ((seq_t)(seqno) % BUFFER_FRAMES) +void do_flush(int64_t timestamp, rtsp_conn_info *conn); + // make timestamps and seqnos definitely monotonic // add an epoch to the timestamp. The monotonic timestamp guaranteed to start between 2^32 and 2^33 @@ -2598,17 +2600,13 @@ void player_volume(double airplay_volume, rtsp_conn_info *conn) { player_volume_without_notification(airplay_volume, conn); } -void player_flush(int64_t timestamp, rtsp_conn_info *conn) { +void do_flush(int64_t timestamp, rtsp_conn_info *conn) { debug(3, "Flush requested up to %u. It seems as if 0 is special.", timestamp); - pthread_rwlock_rdlock(&conn->player_thread_lock); - if (conn->player_thread != NULL) { - pthread_mutex_lock(&conn->flush_mutex); - conn->flush_requested = 1; - // if (timestamp!=0) - conn->flush_rtp_timestamp = timestamp; // flush all packets up to (and including?) this - pthread_mutex_unlock(&conn->flush_mutex); - } - pthread_rwlock_unlock(&conn->player_thread_lock); + pthread_mutex_lock(&conn->flush_mutex); + conn->flush_requested = 1; + // if (timestamp!=0) + conn->flush_rtp_timestamp = timestamp; // flush all packets up to (and including?) this + pthread_mutex_unlock(&conn->flush_mutex); conn->play_segment_reference_frame = 0; conn->play_number_after_flush = 0; #ifdef CONFIG_METADATA @@ -2621,8 +2619,18 @@ void player_flush(int64_t timestamp, rtsp_conn_info *conn) { #endif } +void player_flush(int64_t timestamp, rtsp_conn_info *conn) { + debug(3, "Flush requested up to %u. It seems as if 0 is special.", timestamp); + pthread_rwlock_rdlock(&conn->player_thread_lock); + if (conn->player_thread != NULL) + do_flush(timestamp, conn); + else + debug(1, "Flush requested when player thread is gone."); + pthread_rwlock_unlock(&conn->player_thread_lock); +} + int player_play(rtsp_conn_info *conn) { - // need to use conn in place of streram below. Need to put the stream as a parameter to he + // need to use conn in place of stream below. Need to put the stream as a parameter to he if (conn->player_thread != NULL) die("Trying to create a second player thread for this RTSP session"); if (config.buffer_start_fill > BUFFER_FRAMES) From 4c79dac7de048dca4304e5722b8e7b50b8a7c119 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sat, 12 May 2018 16:09:01 +0100 Subject: [PATCH 19/44] Update RELEASENOTES.md --- RELEASENOTES.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index 2dc3424a..83dee2a1 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,4 +1,8 @@ +Version 3.2d50 +==== +* Add a read-write mutex lock to the player thread so that it can't be accessed while it's being created and initialised or while it's being torn down and destroyed. Make external accessor functions acquire a read lock for access. It's "A Good Thing" and it might help the seg fault problem, which I'm afraid still can't reproduce... + Version 3.2d49 ==== * A few extra debugging messages to try to locate where a segfault is occurring. From 4addf7d215fb4165159af0438c067d04d20b5b14 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sun, 13 May 2018 14:41:15 +0100 Subject: [PATCH 20/44] Fix a misue of rwlock and unlock -- they must be made on the same thread. --- player.c | 7 ++++--- rtsp.c | 2 +- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/player.c b/player.c index 1284a74d..2ce2c349 100644 --- a/player.c +++ b/player.c @@ -1406,12 +1406,13 @@ typedef struct stats { // statistics for running averages } stats_t; static void *player_thread_func(void *arg) { - // note, the thread will be started up with the player_thread_lock locked. You must release it // quickly. rtsp_conn_info *conn = (rtsp_conn_info *)arg; + pthread_rwlock_wrlock(&conn->player_thread_lock); + int rc = pthread_mutex_init(&conn->ab_mutex, NULL); if (rc) debug(1, "Error initialising ab_mutex."); @@ -2617,10 +2618,11 @@ void do_flush(int64_t timestamp, rtsp_conn_info *conn) { send_ssnc_metadata('pfls', NULL, 0, 1); } #endif + debug(3, "Flush request made."); } void player_flush(int64_t timestamp, rtsp_conn_info *conn) { - debug(3, "Flush requested up to %u. It seems as if 0 is special.", timestamp); + debug(3, "player_flush"); pthread_rwlock_rdlock(&conn->player_thread_lock); if (conn->player_thread != NULL) do_flush(timestamp, conn); @@ -2641,7 +2643,6 @@ int player_play(rtsp_conn_info *conn) { debug(2, "pbeg"); send_ssnc_metadata('pbeg', NULL, 0, 1); #endif - pthread_rwlock_wrlock(&conn->player_thread_lock); pthread_t *pt = malloc(sizeof(pthread_t)); if (pt == NULL) die("Couldn't allocate space for pthread_t"); diff --git a/rtsp.c b/rtsp.c index a524428f..d62f61fc 100644 --- a/rtsp.c +++ b/rtsp.c @@ -697,7 +697,7 @@ static void handle_record(rtsp_conn_info *conn, rtsp_message *req, rtsp_message p = strchr(p, '='); if (p) { rtptime = uatoi(p + 1); // unsigned integer -- up to 2^32-1 - rtptime--; + // rtptime--; // debug(1,"RTSP Flush Requested by handle_record: %u.",rtptime); player_flush(rtptime, conn); } From 49a76e64511f887dc5f81aad380a43b54be04f33 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sun, 13 May 2018 14:41:59 +0100 Subject: [PATCH 21/44] Fix a misue of rwlock and unlock -- they must be made on the same thread. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index da112979..2757f5e0 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d50], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d51], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From d02f47e275e0594399c3839076b2e14d405872d8 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Sun, 13 May 2018 15:09:17 +0100 Subject: [PATCH 22/44] Update RELEASENOTES.md --- RELEASENOTES.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index 83dee2a1..d7b96a3e 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,4 +1,8 @@ +Version 3.2d51 +==== +* Fix a small bug locking and unlocking the read-write mutex. It might (and in principle, it could) cause a crash. + Version 3.2d50 ==== * Add a read-write mutex lock to the player thread so that it can't be accessed while it's being created and initialised or while it's being torn down and destroyed. Make external accessor functions acquire a read lock for access. It's "A Good Thing" and it might help the seg fault problem, which I'm afraid still can't reproduce... From 8f76c853ed96897af290915df106b837a49e1830 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Mon, 14 May 2018 10:01:15 +0100 Subject: [PATCH 23/44] clean up audio_pa definition of play --- audio_pa.c | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/audio_pa.c b/audio_pa.c index 3712f3c1..ac1570e0 100644 --- a/audio_pa.c +++ b/audio_pa.c @@ -198,22 +198,21 @@ static void start(__attribute__((unused)) int sample_rate, pa_threaded_mainloop_unlock(mainloop); } -static void play(short buf[], int samples) { +static void play(void *buf, int samples) { // debug(1,"pa_play of %d samples.",samples); - char *bbuf = (char *)buf; // copy the samples into the queue size_t bytes_to_transfer = samples * 2 * 2; size_t space_to_end_of_buffer = audio_umb - audio_eoq; if (space_to_end_of_buffer >= bytes_to_transfer) { - memcpy(audio_eoq, bbuf, bytes_to_transfer); + memcpy(audio_eoq, buf, bytes_to_transfer); audio_occupancy += bytes_to_transfer; pthread_mutex_lock(&buffer_mutex); audio_eoq += bytes_to_transfer; pthread_mutex_unlock(&buffer_mutex); } else { - memcpy(audio_eoq, bbuf, space_to_end_of_buffer); - bbuf += space_to_end_of_buffer; - memcpy(audio_lmb, bbuf, bytes_to_transfer - space_to_end_of_buffer); + memcpy(audio_eoq, buf, space_to_end_of_buffer); + buf += space_to_end_of_buffer; + memcpy(audio_lmb, buf, bytes_to_transfer - space_to_end_of_buffer); pthread_mutex_lock(&buffer_mutex); audio_occupancy += bytes_to_transfer; pthread_mutex_unlock(&buffer_mutex); From 431586726db796051816c0230e2f4823a146bc4e Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Tue, 15 May 2018 09:11:50 +0100 Subject: [PATCH 24/44] Allow a great number of buffers and parameterise the fixed latency limits. --- player.c | 15 ++++++++++----- shairport.c | 4 ++-- 2 files changed, 12 insertions(+), 7 deletions(-) diff --git a/player.c b/player.c index 2ce2c349..046fded6 100644 --- a/player.c +++ b/player.c @@ -512,11 +512,19 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp } // here, we should check for missing frames + const int number_of_resend_attempts = 8; if (!conn->ab_buffering) { int j; - for (j = 1; j <= 8; j++) { + for (j = 1; j <= number_of_resend_attempts; j++) { // check j times, after a short period of has elapsed, assuming 352 frames per packet - int back_step = (((250 * 44100) / 352) / 1000) * (j); // approx 250 ms intervals + // int back_step = (((250 * 44100) / 352) / 1000) * (j); // approx 250 ms intervals + // int back_step = ((BUFFER_FRAMES-(22050/352)) / number_of_resend_attempts) * j; + int back_step = ((seq_diff(conn->ab_read, conn->ab_write, + conn->ab_read)-(22050/352)) / number_of_resend_attempts) * j; + if (back_step<(((190 * 44100) / 352) / 1000) * j) { + // debug(1,"resend request back_step %d is too small. Reset to %d.",back_step,(((190 * 44100) / 352) / 1000) * j); + back_step = (((190 * 44100) / 352) / 1000) * j; + } int k; for (k = -2; k <= 2; k++) { if (back_step < @@ -1217,9 +1225,6 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { // seq_t read = conn->ab_read; - // check if t+8, t+16, t+32, t+64, t+128, ... (buffer_start_fill / 2) - // packets have arrived... last-chance resend - if (!curframe->ready) { // debug(1, "Supplying a silent frame for frame %u", read); conn->missing_packets++; diff --git a/shairport.c b/shairport.c index fcb7629c..30dc9d65 100644 --- a/shairport.c +++ b/shairport.c @@ -1362,8 +1362,8 @@ int main(int argc, char **argv) { "latency from the source."); inform("Please remove this setting and use the relevant audio_backend_latency_offset setting, " "if necessary, to compensate for delays elsewhere."); - if ((config.userSuppliedLatency!=0) && ((config.userSuppliedLatency<4410) || (config.userSuppliedLatency>154350))) - die("An out-of-range fixed latency has been specified. It must be between 4,410 and 154,350."); + if ((config.userSuppliedLatency!=0) && ((config.userSuppliedLatency<4410) || (config.userSuppliedLatency>BUFFER_FRAMES*352-22050))) + die("An out-of-range fixed latency has been specified. It must be between 4410 and %d (at 44100 frames per second).",BUFFER_FRAMES*352-22050); } /* print out version */ From c2849b71ee334e6e676fd06191ce1faee5728e4a Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Tue, 15 May 2018 09:12:17 +0100 Subject: [PATCH 25/44] Allow a great number of buffers and parameterise the fixed latency limits. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 2757f5e0..7191775b 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d51], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d52], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From b9d3a036b11758a503b92eb56de865a8afb8772d Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Tue, 15 May 2018 12:08:01 +0100 Subject: [PATCH 26/44] Revise resend interval calculation to spread it out over a long latency. --- player.c | 31 ++++++++++++++++++------------- player.h | 13 ++++++++++++- shairport.c | 28 ++++++++++++++++------------ 3 files changed, 46 insertions(+), 26 deletions(-) diff --git a/player.c b/player.c index 046fded6..61cb2563 100644 --- a/player.c +++ b/player.c @@ -512,25 +512,30 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp } // here, we should check for missing frames + int resend_interval = (((250 * 44100) / 352) / 1000); // approximately 250 ms intervals const int number_of_resend_attempts = 8; + int latency_based_resend_interval = + (conn->latency) / (number_of_resend_attempts * conn->max_frames_per_packet); + if (latency_based_resend_interval > resend_interval) + resend_interval = latency_based_resend_interval; + + if (conn->resend_interval != resend_interval) { + debug(1, "Resend interval for latency of %" PRId64 " frames is %d frames.", conn->latency, + resend_interval); + conn->resend_interval = resend_interval; + } if (!conn->ab_buffering) { int j; for (j = 1; j <= number_of_resend_attempts; j++) { // check j times, after a short period of has elapsed, assuming 352 frames per packet - // int back_step = (((250 * 44100) / 352) / 1000) * (j); // approx 250 ms intervals - // int back_step = ((BUFFER_FRAMES-(22050/352)) / number_of_resend_attempts) * j; - int back_step = ((seq_diff(conn->ab_read, conn->ab_write, - conn->ab_read)-(22050/352)) / number_of_resend_attempts) * j; - if (back_step<(((190 * 44100) / 352) / 1000) * j) { - // debug(1,"resend request back_step %d is too small. Reset to %d.",back_step,(((190 * 44100) / 352) / 1000) * j); - back_step = (((190 * 44100) / 352) / 1000) * j; - } + + int back_step = resend_interval * j; + + int32_t sd = seq_diff(conn->ab_read, conn->ab_write, conn->ab_read); int k; for (k = -2; k <= 2; k++) { - if (back_step < - seq_diff(conn->ab_read, conn->ab_write, - conn->ab_read)) { // if it's within the range of frames in use... - int item_to_check = (conn->ab_write - back_step) & 0xffff; + if ((back_step + k) < sd) { // if it's within the range of frames in use... + int item_to_check = (conn->ab_write - back_step + k) & 0xffff; seq_t next = item_to_check; abuf_t *check_buf = conn->audio_buffer + BUFIDX(next); if ((!check_buf->ready) && @@ -539,7 +544,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp check_buf->resend_level = j; if (config.disable_resend_requests == 0) { rtp_request_resend(next, 1, conn); - if (j >= 6) + if (j >= number_of_resend_attempts - 2) debug(2, "Resend request level #%d for packet %u in range %u to %u.", j, next, conn->ab_read, conn->ab_write); conn->resend_requests++; diff --git a/player.h b/player.h index e6339477..d941c658 100644 --- a/player.h +++ b/player.h @@ -46,7 +46,17 @@ typedef struct audio_buffer_entry { // decoded audio packets } abuf_t; // default buffer size -// needs to be a power of 2 because of the way BUFIDX(seqno) works +// This eeds to be a power of 2 because of the way BUFIDX(seqno) works. +// 512 is the minimum for normal operation -- it gives 512*352/44100 or just over 4 seconds of +// buffers. +// For at least 10 seconds, you need to go to 2048. +// Resend requests will be spaced out evenly in the latency period, subject to a minimum interval of +// about 0.25 seconds. +// Each buffer occupies 352*4 bytes plus about, say, 64 bytes of overhead in various places, say +// rougly 1,500 bytes per buffer. +// Thus, 2048 buffers will occupy about 3 megabytes -- no big deal in a normal machine but maybe a +// problem in an embedded device. + #define BUFFER_FRAMES 1024 typedef struct { @@ -57,6 +67,7 @@ typedef struct { typedef struct { int connection_number; // for debug ID purposes, nothing else... + int resend_interval; // this is really just for debugging int AirPlayVersion; // zero if not an AirPlay session. Used to help calculate latency int64_t latency; // the actual latency used for this play session int64_t minimum_latency; // set if an a=min-latency: line appears in the ANNOUNCE message; zero diff --git a/shairport.c b/shairport.c index 30dc9d65..9ce8b7de 100644 --- a/shairport.c +++ b/shairport.c @@ -274,7 +274,7 @@ int parse_options(int argc, char **argv) { optind = j; optCon = poptGetContext(NULL, optind, (const char **)argv, optionsTable, 0); - if (optCon==NULL) + if (optCon == NULL) die("Can not get a secondary popt context."); poptSetOtherOptionHelp(optCon, "[OPTIONS]* "); @@ -321,7 +321,7 @@ int parse_options(int argc, char **argv) { } poptFreeContext(optCon); - + if ((daemonisewith) && (daemonisewithout)) die("Select either daemonize_with_pid_file or daemonize_without_pid_file -- you have selected " "both!"); @@ -892,7 +892,7 @@ int parse_options(int argc, char **argv) { optind = j; optCon = poptGetContext(NULL, optind, (const char **)argv, optionsTable, 0); - if (optCon==NULL) + if (optCon == NULL) die("Can not get a popt context."); poptSetOtherOptionHelp(optCon, "[OPTIONS]* "); @@ -1052,13 +1052,13 @@ void shairport_startup_complete(void) { } } -const char *pid_file_proc(char* fn,size_t max_length) { +const char *pid_file_proc(char *fn, size_t max_length) { if (fn) { snprintf(fn, max_length, "%s/%s.pid", config.computed_piddir, daemon_pid_file_ident ? daemon_pid_file_ident : "unknown"); // debug(1,"fn \"%s\".",fn); } else { - debug(1,"the sise of the buffer for the PID file path is zero."); + debug(1, "the sise of the buffer for the PID file path is zero."); } return fn; } @@ -1358,12 +1358,16 @@ int main(int argc, char **argv) { // audio_backend_latency_offset instead. if (config.userSuppliedLatency) { - inform("The fixed latency setting is deprecated, as Shairport Sync can now get the correct " - "latency from the source."); - inform("Please remove this setting and use the relevant audio_backend_latency_offset setting, " - "if necessary, to compensate for delays elsewhere."); - if ((config.userSuppliedLatency!=0) && ((config.userSuppliedLatency<4410) || (config.userSuppliedLatency>BUFFER_FRAMES*352-22050))) - die("An out-of-range fixed latency has been specified. It must be between 4410 and %d (at 44100 frames per second).",BUFFER_FRAMES*352-22050); + inform("The fixed latency setting is deprecated, as Shairport Sync gets the correct " + "latency automatically from the source."); + inform("Use the audio_backend_latency_offset_in_seconds setting " + "instead to compensate for timing issues."); + if ((config.userSuppliedLatency != 0) && + ((config.userSuppliedLatency < 4410) || + (config.userSuppliedLatency > BUFFER_FRAMES * 352 - 22050))) + die("An out-of-range fixed latency has been specified. It must be between 4410 and %d (at " + "44100 frames per second).", + BUFFER_FRAMES * 352 - 22050); } /* print out version */ @@ -1380,7 +1384,7 @@ int main(int argc, char **argv) { /* Print out options */ debug(1, "statistics_requester status is %d.", config.statistics_requested); debug(1, "daemon status is %d.", config.daemonise); - debug(1, "deamon pid file is \"%s\".", pid_file_proc(pid_file_path_string,4096)); + debug(1, "deamon pid file is \"%s\".", pid_file_proc(pid_file_path_string, 4096)); 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); From 8f06651c479cae310f89b1826d01ef577e7de631 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Tue, 15 May 2018 12:45:26 +0100 Subject: [PATCH 27/44] Make the resend failure message a bit less chatty and more informative. --- player.c | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/player.c b/player.c index 61cb2563..f1e1e6bd 100644 --- a/player.c +++ b/player.c @@ -520,7 +520,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp resend_interval = latency_based_resend_interval; if (conn->resend_interval != resend_interval) { - debug(1, "Resend interval for latency of %" PRId64 " frames is %d frames.", conn->latency, + debug(2, "Resend interval for latency of %" PRId64 " frames is %d frames.", conn->latency, resend_interval); conn->resend_interval = resend_interval; } @@ -544,9 +544,9 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp check_buf->resend_level = j; if (config.disable_resend_requests == 0) { rtp_request_resend(next, 1, conn); - if (j >= number_of_resend_attempts - 2) - debug(2, "Resend request level #%d for packet %u in range %u to %u.", j, next, - conn->ab_read, conn->ab_write); + if ((back_step + k + resend_interval) >= sd) + debug(2, "Last-ditch (#%d) resend request for packet %u in range %u to %u. Looking back %d packets.", j, next, + conn->ab_read, conn->ab_write,back_step + k); conn->resend_requests++; } } From 9aa920ab81ed18fd1c1767f33033ed38eaf67cbb Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Wed, 16 May 2018 18:32:17 +0100 Subject: [PATCH 28/44] Fix a benign type definition mismatch --- audio_ao.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/audio_ao.c b/audio_ao.c index 3b58ca7c..9c87f892 100644 --- a/audio_ao.c +++ b/audio_ao.c @@ -121,7 +121,7 @@ static void deinit(void) { static void start(__attribute__((unused)) int sample_rate, __attribute__((unused)) int sample_format) {} -static void play(short buf[], int samples) { ao_play(dev, (char *)buf, samples * 4); } +static void play(void * buf, int samples) { ao_play(dev, buf, samples * 4); } static void stop(void) {} From 7d0eb379589317a4f2a37218fdae9ab8bfb690dd Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 10:16:44 +0100 Subject: [PATCH 29/44] Move to using pthread_cancel in place of pthread_kill -- due to a problem in CYGWIN, but the move makes the code simpler and more rugged. --- mdns.c | 4 +- player.c | 24 ++---- player.h | 2 - rtp.c | 225 ++++++++++++++++++++++--------------------------------- rtsp.c | 5 +- 5 files changed, 100 insertions(+), 160 deletions(-) diff --git a/mdns.c b/mdns.c index e45dacc5..f6a191a3 100644 --- a/mdns.c +++ b/mdns.c @@ -113,7 +113,7 @@ void *mdns_dacp_monitor(char *dacp_id) { debug(1, "Error starting a DACP monitor."); } } else - debug(1, "Can't start a DACP monitor -- none registered."); + debug(3, "Can't start a DACP monitor -- none registered."); } return reply; } @@ -122,7 +122,7 @@ void mdns_dacp_dont_monitor(void *userdata) { if ((config.mdns) && (config.mdns->mdns_dacp_dont_monitor)) { config.mdns->mdns_dacp_dont_monitor(userdata); } else - debug(1, "Can't stop a DACP monitor -- none registered."); + debug(3, "Can't stop a DACP monitor -- none registered."); } void mdns_ls_backends(void) { mdns_backend **b = NULL; diff --git a/player.c b/player.c index f1e1e6bd..41199da9 100644 --- a/player.c +++ b/player.c @@ -1449,7 +1449,6 @@ static void *player_thread_func(void *arg) { // it's safe now - conn->please_stop = 0; conn->packet_count = 0; conn->previous_random_number = 0; conn->input_bytes_per_frame = 4; @@ -2305,7 +2304,7 @@ static void *player_thread_func(void *arg) { } } - debug(3, "Play thread main loop exited."); + debug(3, "Connection %d: player thread main loop exit.", conn->connection_number); if (config.statistics_requested) { int rawSeconds = (int)difftime(time(NULL), playstart); @@ -2327,23 +2326,16 @@ static void *player_thread_func(void *arg) { if (config.output->stop) config.output->stop(); - debug(2, "Shutting down audio, control and timing threads"); - conn->please_stop = 1; - pthread_kill(rtp_audio_thread, SIGUSR1); - pthread_kill(rtp_control_thread, SIGUSR1); - pthread_kill(rtp_timing_thread, SIGUSR1); + debug(3, "Shutting down timing, control and audio threads"); + pthread_cancel(rtp_timing_thread); pthread_join(rtp_timing_thread, NULL); - debug(2, "timing thread joined"); - pthread_join(rtp_audio_thread, NULL); - debug(2, "audio thread joined"); + pthread_cancel(rtp_control_thread); pthread_join(rtp_control_thread, NULL); - debug(2, "control thread joined"); + pthread_cancel(rtp_audio_thread); + pthread_join(rtp_audio_thread, NULL); 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 - debug(3, "Freeing audio buffers and decoders."); free_audio_buffers(conn); @@ -2362,7 +2354,7 @@ static void *player_thread_func(void *arg) { if (rc) debug(1, "Error destroying vol_mutex variable."); - debug(2, "Player thread exit on RTSP conversation thread %d.", conn->connection_number); + debug(2, "Connection %d: player thread terminated.", conn->connection_number); if (conn->dacp_id) { free(conn->dacp_id); conn->dacp_id = NULL; @@ -2373,7 +2365,7 @@ static void *player_thread_func(void *arg) { free(tbuf); if (sbuf) free(sbuf); - return 0; + pthread_exit(NULL); } // takes the volume as specified by the airplay protocol diff --git a/player.h b/player.h index d941c658..eb8046e6 100644 --- a/player.h +++ b/player.h @@ -93,7 +93,6 @@ typedef struct { int max_frame_size_change; int64_t previous_random_number; alac_file *decoder_info; - uint32_t please_stop; uint64_t packet_count; int connection_state_to_output; int player_thread_please_stop; @@ -180,7 +179,6 @@ typedef struct { uint64_t local_to_remote_time_difference; // used to switch between local and remote clocks - int timing_sender_stop; // for asking the timing-sending thread to stop int last_stuff_request; int64_t play_segment_reference_frame; diff --git a/rtp.c b/rtp.c index 4189d165..a900c7a4 100644 --- a/rtp.c +++ b/rtp.c @@ -48,8 +48,6 @@ uint64_t local_to_remote_time_jitters; uint64_t local_to_remote_time_jitters_count; -void memory_barrier(); - void rtp_initialise(rtsp_conn_info *conn) { conn->rtp_time_of_last_resend_request_error_fp = 0; conn->rtp_running = 0; @@ -67,10 +65,13 @@ void rtp_terminate(rtsp_conn_info *conn) { debug(1, "Error destroying reference_time_mutex variable."); } -void *rtp_audio_receiver(void *arg) { - debug(3, "Audio receiver -- Server RTP thread starting."); +void rtp_audio_receiver_cleanup_handler(void *arg) { + rtsp_conn_info *conn = (rtsp_conn_info *)arg; + close(conn->audio_socket); +} - // we inherit the signal mask (SIGUSR1) +void *rtp_audio_receiver(void *arg) { + pthread_cleanup_push(rtp_audio_receiver_cleanup_handler, arg); rtsp_conn_info *conn = (rtsp_conn_info *)arg; int32_t last_seqno = -1; @@ -87,17 +88,8 @@ void *rtp_audio_receiver(void *arg) { float stat_M2 = 0.0; ssize_t nread; - while (conn->please_stop == 0) { - fd_set readfds; - FD_ZERO(&readfds); - FD_SET(conn->audio_socket, &readfds); - do { - memory_barrier(); - } while (conn->please_stop == 0 && - pselect(conn->audio_socket + 1, &readfds, NULL, NULL, NULL, &pselect_sigset) <= 0); - if (conn->please_stop != 0) { - break; - } + while (1) { + nread = recv(conn->audio_socket, packet, sizeof(packet), 0); uint64_t local_time_now_fp = get_absolute_time_in_fp(); @@ -181,17 +173,24 @@ void *rtp_audio_receiver(void *arg) { } } + /* debug(3, "Audio receiver -- Server RTP thread interrupted. terminating."); close(conn->audio_socket); + */ + + debug(1, "Audio receiver thread \"normal\" exit -- this can't happen. Hah!"); + pthread_cleanup_pop(0); // don't execute anything here. + debug(2, "Audio receiver thread exit."); + pthread_exit(NULL); +} - return NULL; +void rtp_control_handler_cleanup_handler(void *arg) { + rtsp_conn_info *conn = (rtsp_conn_info *)arg; + close(conn->control_socket); } void *rtp_control_receiver(void *arg) { - // we inherit the signal mask (SIGUSR1) - - debug(3, "Control receiver -- Server RTP thread starting."); - + pthread_cleanup_push(rtp_control_handler_cleanup_handler, arg); rtsp_conn_info *conn = (rtsp_conn_info *)arg; conn->reference_timestamp = 0; // nothing valid received yet @@ -200,18 +199,7 @@ void *rtp_control_receiver(void *arg) { uint64_t remote_time_of_sync; int64_t sync_rtp_timestamp; ssize_t nread; - while (conn->please_stop == 0) { - fd_set readfds; - FD_ZERO(&readfds); - FD_SET(conn->control_socket, &readfds); - do { - memory_barrier(); - } while (conn->please_stop == 0 && - pselect(conn->control_socket + 1, &readfds, NULL, NULL, NULL, &pselect_sigset) <= 0); - if (conn->please_stop != 0) { - break; - } - + while (1) { nread = recv(conn->control_socket, packet, sizeof(packet), 0); // local_time_now = get_absolute_time_in_fp(); // clock_gettime(CLOCK_MONOTONIC,&tn); @@ -223,50 +211,50 @@ void *rtp_control_receiver(void *arg) { (drand48() > config.diagnostic_drop_packet_fraction)) { ssize_t plen = nread; - if (packet[1] == 0xd4) { // sync data - /* - // the following stanza is for debugging only -- normally commented out. - { - char obf[4096]; - char *obfp = obf; - int obfc; - for (obfc = 0; obfc < plen; obfc++) { - snprintf(obfp, 3, "%02X", packet[obfc]); - obfp += 2; - }; - *obfp = 0; - - - // get raw timestamp information - // I think that a good way to understand these timestamps is that - // (1) the rtlt below is the timestamp of the frame that should be playing at the - client-time specified in the packet if there was no delay - // and (2) that the rt below is the timestamp of the frame that should be playing - at - the client-time specified in the packet on this device taking account of the delay - // Thus, (3) the latency can be calculated by subtracting the second from the - first. - // There must be more to it -- there something missing. - - // In addition, it seems that if the value of the short represented by the second - pair - of bytes in the packe is 7 - // then an extra time lag is expected to be added, presumably by the AirPort - Express. - Best guess is that this delay is 11,025 frames. - - // uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency - // uint32_t rt = nctohl(&packet[16]); // raw timestamp - - // uint32_t fl = nctohs(&packet[2]); // - - // debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and - %u, - giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt); - // debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 " - respectively.",monotonic_timestamp(rt, conn),monotonic_timestamp(rtlt, conn)); - } - */ + if (packet[1] == 0xd4) { // sync data + /* + // the following stanza is for debugging only -- normally commented out. + { + char obf[4096]; + char *obfp = obf; + int obfc; + for (obfc = 0; obfc < plen; obfc++) { + snprintf(obfp, 3, "%02X", packet[obfc]); + obfp += 2; + }; + *obfp = 0; + + + // get raw timestamp information + // I think that a good way to understand these timestamps is that + // (1) the rtlt below is the timestamp of the frame that should be playing at the + // client-time specified in the packet if there was no delay + // and (2) that the rt below is the timestamp of the frame that should be playing + // at the client-time specified in the packet on this device taking account of + // the delay + // Thus, (3) the latency can be calculated by subtracting the second from the + // first. + // There must be more to it -- there something missing. + + // In addition, it seems that if the value of the short represented by the second + // pair of bytes in the packe is 7 + // then an extra time lag is expected to be added, presumably by + // the AirPort Express. + + // Best guess is that this delay is 11,025 frames. + + // uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency + // uint32_t rt = nctohl(&packet[16]); // raw timestamp + + // uint32_t fl = nctohs(&packet[2]); // + + // debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and + %u, + giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt); + // debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 " + respectively.",monotonic_timestamp(rt, conn),monotonic_timestamp(rtlt, conn)); + } + */ if (conn->local_to_remote_time_difference) { // need a time packet to be interchanged // first... @@ -406,15 +394,13 @@ void *rtp_control_receiver(void *arg) { debug(1, "Control Receiver -- error receiving a packet."); } } - - debug(3, "Control RTP thread interrupted. terminating."); - close(conn->control_socket); - - return NULL; + debug(1, "Control RTP thread \"normal\" exit -- this can't happen. Hah!"); + pthread_cleanup_pop(0); // don't execute anything here. + debug(2, "Control RTP thread exit."); + pthread_exit(NULL); } void *rtp_timing_sender(void *arg) { - debug(3, "Timing sender thread starting."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; struct timing_request { char leader; @@ -434,9 +420,7 @@ void *rtp_timing_sender(void *arg) { req.seqno = htons(7); conn->time_ping_count = 0; - - // we inherit the signal mask (SIGUSR1) - while (conn->timing_sender_stop == 0) { + while (1) { // debug(1,"Send a timing request"); if (!conn->rtp_running) @@ -456,17 +440,6 @@ void *rtp_timing_sender(void *arg) { msgsize = sizeof(struct sockaddr_in6); } #endif - fd_set writefds; - FD_ZERO(&writefds); - FD_SET(conn->timing_socket, &writefds); - do { - memory_barrier(); - } while (conn->timing_sender_stop == 0 && - pselect(conn->timing_socket + 1, NULL, &writefds, NULL, NULL, &pselect_sigset) <= 0); - if (conn->timing_sender_stop != 0) { - break; - } - if ((config.diagnostic_drop_packet_fraction == 0.0) || (drand48() > config.diagnostic_drop_packet_fraction)) { if (sendto(conn->timing_socket, &req, sizeof(req), 0, @@ -481,35 +454,30 @@ void *rtp_timing_sender(void *arg) { 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) - wait_time = 500000; + usleep(500000); //these are thread cancellation points else - wait_time = 3000000; - while ((wait_time > 0) && (conn->timing_sender_stop == 0)) { - usleep(wait_interval); - wait_time -= wait_interval; - } + usleep(3000000); } debug(3, "rtp_timing_sender thread interrupted. terminating."); - return NULL; + pthread_exit(NULL); +} + +pthread_t timer_requester; + +void rtp_timing_receiver_cleanup_handler(void *arg) { + rtsp_conn_info *conn = (rtsp_conn_info *)arg; + pthread_cancel(timer_requester); + pthread_join(timer_requester, NULL); + close(conn->timing_socket); } void *rtp_timing_receiver(void *arg) { - debug(3, "Timing receiver -- Server RTP thread starting."); - // we inherit the signal mask (SIGUSR1) + pthread_cleanup_push(rtp_timing_receiver_cleanup_handler, arg); rtsp_conn_info *conn = (rtsp_conn_info *)arg; uint8_t packet[2048]; ssize_t nread; - conn->timing_sender_stop = 0; - pthread_t timer_requester; pthread_create(&timer_requester, NULL, &rtp_timing_sender, arg); // struct timespec att; uint64_t distant_receive_time, distant_transmit_time, arrival_time, return_time; @@ -521,17 +489,7 @@ void *rtp_timing_receiver(void *arg) { uint64_t first_local_to_remote_time_difference = 0; // uint64_t first_local_to_remote_time_difference_time; // uint64_t l2rtd = 0; - while (conn->please_stop == 0) { - fd_set readfds; - FD_ZERO(&readfds); - FD_SET(conn->timing_socket, &readfds); - do { - memory_barrier(); - } while (conn->please_stop == 0 && - pselect(conn->timing_socket + 1, &readfds, NULL, NULL, NULL, &pselect_sigset) <= 0); - if (conn->please_stop != 0) { - break; - } + while (1) { nread = recv(conn->timing_socket, packet, sizeof(packet), 0); if (nread >= 0) { @@ -738,17 +696,10 @@ void *rtp_timing_receiver(void *arg) { } } - debug(3, "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."); - close(conn->timing_socket); - - return NULL; + debug(1, "Timing Receiver RTP thread \"normal\" exit -- this can't happen. Hah!"); + pthread_cleanup_pop(0); // don't execute anything here. + debug(2, "Timing Receiver RTP thread exit."); + pthread_exit(NULL); } static uint16_t bind_port(int ip_family, const char *self_ip_address, uint32_t scope_id, diff --git a/rtsp.c b/rtsp.c index d62f61fc..8366069c 100644 --- a/rtsp.c +++ b/rtsp.c @@ -1972,8 +1972,7 @@ static void *rtsp_conversation_thread_func(void *pconn) { playing_conn = NULL; pthread_mutex_unlock(&play_lock); } - debug(2, "RTSP conversation thread %d terminated.", conn->connection_number); - // please_shutdown = 0; + debug(2, "Connection %d: RTSP thread terminated.", conn->connection_number); conn->running = 0; // release the player_thread_lock @@ -1982,7 +1981,7 @@ static void *rtsp_conversation_thread_func(void *pconn) { debug(1, "Error %d destroying player_thread_lock for conversation thread %d.", rwld, conn->connection_number); - return NULL; + pthread_exit(NULL); } /* From 8a5a29e2c25b7043b449fc2f836f6c3b11916de5 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 10:29:59 +0100 Subject: [PATCH 30/44] Move to using pthread_cancel in place of pthread_kill -- due to a problem in CYGWIN, but the move makes the code simpler and more rugged. Tidy up the code a bit and remove a clobbering warning. --- audio_ao.c | 2 +- mdns.c | 16 ++++---- player.c | 5 ++- rtp.c | 108 +++++++++++++++++++++++++++-------------------------- 4 files changed, 67 insertions(+), 64 deletions(-) diff --git a/audio_ao.c b/audio_ao.c index 9c87f892..8a78e880 100644 --- a/audio_ao.c +++ b/audio_ao.c @@ -121,7 +121,7 @@ static void deinit(void) { static void start(__attribute__((unused)) int sample_rate, __attribute__((unused)) int sample_format) {} -static void play(void * buf, int samples) { ao_play(dev, buf, samples * 4); } +static void play(void *buf, int samples) { ao_play(dev, buf, samples * 4); } static void stop(void) {} diff --git a/mdns.c b/mdns.c index f6a191a3..b8d870c6 100644 --- a/mdns.c +++ b/mdns.c @@ -106,14 +106,14 @@ void mdns_unregister(void) { void *mdns_dacp_monitor(char *dacp_id) { void *reply = NULL; - if ((dacp_id!=NULL) && (*dacp_id!='\0')) { - if ((config.mdns) && (config.mdns->mdns_dacp_monitor)) { - reply = config.mdns->mdns_dacp_monitor(dacp_id); - if (reply == NULL) { - debug(1, "Error starting a DACP monitor."); - } - } else - debug(3, "Can't start a DACP monitor -- none registered."); + if ((dacp_id != NULL) && (*dacp_id != '\0')) { + if ((config.mdns) && (config.mdns->mdns_dacp_monitor)) { + reply = config.mdns->mdns_dacp_monitor(dacp_id); + if (reply == NULL) { + debug(1, "Error starting a DACP monitor."); + } + } else + debug(3, "Can't start a DACP monitor -- none registered."); } return reply; } diff --git a/player.c b/player.c index 41199da9..8e29678a 100644 --- a/player.c +++ b/player.c @@ -545,8 +545,9 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp if (config.disable_resend_requests == 0) { rtp_request_resend(next, 1, conn); if ((back_step + k + resend_interval) >= sd) - debug(2, "Last-ditch (#%d) resend request for packet %u in range %u to %u. Looking back %d packets.", j, next, - conn->ab_read, conn->ab_write,back_step + k); + debug(2, "Last-ditch (#%d) resend request for packet %u in range %u to %u. " + "Looking back %d packets.", + j, next, conn->ab_read, conn->ab_write, back_step + k); conn->resend_requests++; } } diff --git a/rtp.c b/rtp.c index a900c7a4..e15c18ad 100644 --- a/rtp.c +++ b/rtp.c @@ -177,7 +177,7 @@ void *rtp_audio_receiver(void *arg) { debug(3, "Audio receiver -- Server RTP thread interrupted. terminating."); close(conn->audio_socket); */ - + debug(1, "Audio receiver thread \"normal\" exit -- this can't happen. Hah!"); pthread_cleanup_pop(0); // don't execute anything here. debug(2, "Audio receiver thread exit."); @@ -211,50 +211,50 @@ void *rtp_control_receiver(void *arg) { (drand48() > config.diagnostic_drop_packet_fraction)) { ssize_t plen = nread; - if (packet[1] == 0xd4) { // sync data - /* - // the following stanza is for debugging only -- normally commented out. - { - char obf[4096]; - char *obfp = obf; - int obfc; - for (obfc = 0; obfc < plen; obfc++) { - snprintf(obfp, 3, "%02X", packet[obfc]); - obfp += 2; - }; - *obfp = 0; - - - // get raw timestamp information - // I think that a good way to understand these timestamps is that - // (1) the rtlt below is the timestamp of the frame that should be playing at the - // client-time specified in the packet if there was no delay - // and (2) that the rt below is the timestamp of the frame that should be playing - // at the client-time specified in the packet on this device taking account of - // the delay - // Thus, (3) the latency can be calculated by subtracting the second from the - // first. - // There must be more to it -- there something missing. - - // In addition, it seems that if the value of the short represented by the second - // pair of bytes in the packe is 7 - // then an extra time lag is expected to be added, presumably by - // the AirPort Express. - - // Best guess is that this delay is 11,025 frames. - - // uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency - // uint32_t rt = nctohl(&packet[16]); // raw timestamp - - // uint32_t fl = nctohs(&packet[2]); // - - // debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and - %u, - giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt); - // debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 " - respectively.",monotonic_timestamp(rt, conn),monotonic_timestamp(rtlt, conn)); - } - */ + if (packet[1] == 0xd4) { // sync data + /* + // the following stanza is for debugging only -- normally commented out. + { + char obf[4096]; + char *obfp = obf; + int obfc; + for (obfc = 0; obfc < plen; obfc++) { + snprintf(obfp, 3, "%02X", packet[obfc]); + obfp += 2; + }; + *obfp = 0; + + + // get raw timestamp information + // I think that a good way to understand these timestamps is that + // (1) the rtlt below is the timestamp of the frame that should be playing at the + // client-time specified in the packet if there was no delay + // and (2) that the rt below is the timestamp of the frame that should be playing + // at the client-time specified in the packet on this device taking account of + // the delay + // Thus, (3) the latency can be calculated by subtracting the second from the + // first. + // There must be more to it -- there something missing. + + // In addition, it seems that if the value of the short represented by the second + // pair of bytes in the packe is 7 + // then an extra time lag is expected to be added, presumably by + // the AirPort Express. + + // Best guess is that this delay is 11,025 frames. + + // uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency + // uint32_t rt = nctohl(&packet[16]); // raw timestamp + + // uint32_t fl = nctohs(&packet[2]); // + + // debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and + %u, + giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt); + // debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 " + respectively.",monotonic_timestamp(rt, conn),monotonic_timestamp(rtlt, conn)); + } + */ if (conn->local_to_remote_time_difference) { // need a time packet to be interchanged // first... @@ -455,7 +455,7 @@ void *rtp_timing_sender(void *arg) { request_number++; if (request_number <= 4) - usleep(500000); //these are thread cancellation points + usleep(500000); // these are thread cancellation points else usleep(3000000); } @@ -518,9 +518,9 @@ void *rtp_timing_receiver(void *arg) { return_time = arrival_time - conn->departure_time; - uint64_t rtus = (return_time * 1000000) >> 32; + //uint64_t rtus = (return_time * 1000000) >> 32; - if (rtus < 300000) { + if (((return_time * 1000000) >> 32) < 300000) { // debug(2,"Synchronisation ping return time is %f milliseconds.",(rtus*1.0)/1000); @@ -683,7 +683,7 @@ void *rtp_timing_receiver(void *arg) { //(return_time*1000000)>>32); } else { debug(2, "Time ping turnaround time: %lld us -- it looks like a timing ping was lost.", - rtus); + (return_time * 1000000) >> 32); } } else { debug(1, "Timing port -- Unknown RTP packet of type 0x%02X length %d.", packet[1], nread); @@ -947,8 +947,8 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { (struct sockaddr *)&conn->rtp_client_control_socket, msgsize) == -1) { char em[1024]; strerror_r(errno, em, sizeof(em)); - debug(1, - "Error %d using send-to to an audio socket: \"%s\". Backing off for 1/16th of a second.", + debug(1, "Error %d using send-to to an audio socket: \"%s\". Backing off for 1/16th of a " + "second.", errno, em); conn->rtp_time_of_last_resend_request_error_fp = time_of_sending_fp; } else { @@ -956,8 +956,10 @@ void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { } } else { - debug(3, "Dropping resend request packet to simulate a bad network. Backing off for 1/16th of a " - "second."); + debug( + 3, + "Dropping resend request packet to simulate a bad network. Backing off for 1/16th of a " + "second."); conn->rtp_time_of_last_resend_request_error_fp = time_of_sending_fp; } } else { From a8cd696f8d25c86b4c69727e54c026a55f6cc318 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 10:58:22 +0100 Subject: [PATCH 31/44] Fix an off-by-one bug causing excessive resend requests. --- player.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/player.c b/player.c index 8e29678a..32434ed3 100644 --- a/player.c +++ b/player.c @@ -535,7 +535,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp int k; for (k = -2; k <= 2; k++) { if ((back_step + k) < sd) { // if it's within the range of frames in use... - int item_to_check = (conn->ab_write - back_step + k) & 0xffff; + int item_to_check = (conn->ab_write - (back_step + k)) & 0xffff; seq_t next = item_to_check; abuf_t *check_buf = conn->audio_buffer + BUFIDX(next); if ((!check_buf->ready) && From 5fdcaf4cb0dfb6d3d1db83333503b602a04ef993 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 10:59:16 +0100 Subject: [PATCH 32/44] Move to using pthread_cancel in place of pthread_kill -- due to a problem in CYGWIN, but the move makes the code simpler and more rugged. Tidy up the code a bit and remove a clobbering warning. Fix a bug casung excessive resend requests. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 7191775b..70e5fa0a 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d52], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d53], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From d0237fb42070a6f941cb39032c63f9ce9650bf7c Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 11:29:59 +0100 Subject: [PATCH 33/44] Change some debug messages. --- player.c | 12 ++++++++---- rtp.c | 3 +++ 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/player.c b/player.c index 32434ed3..67fac035 100644 --- a/player.c +++ b/player.c @@ -2327,17 +2327,21 @@ static void *player_thread_func(void *arg) { if (config.output->stop) config.output->stop(); - debug(3, "Shutting down timing, control and audio threads"); + debug(2, "Cancelling timing, control and audio threads"); pthread_cancel(rtp_timing_thread); - pthread_join(rtp_timing_thread, NULL); pthread_cancel(rtp_control_thread); - pthread_join(rtp_control_thread, NULL); pthread_cancel(rtp_audio_thread); + debug(2, "Joining terminated threads."); + pthread_join(rtp_timing_thread, NULL); + debug(2, "Timing thread terminated."); + pthread_join(rtp_control_thread, NULL); + debug(2, "Control thread terminated."); pthread_join(rtp_audio_thread, NULL); + debug(2, "Audio thread terminated."); clear_reference_timestamp(conn); conn->rtp_running = 0; - debug(3, "Freeing audio buffers and decoders."); + debug(2, "Freeing audio buffers and decoders."); free_audio_buffers(conn); terminate_decoders(conn); diff --git a/rtp.c b/rtp.c index e15c18ad..cecae3e7 100644 --- a/rtp.c +++ b/rtp.c @@ -68,6 +68,7 @@ void rtp_terminate(rtsp_conn_info *conn) { void rtp_audio_receiver_cleanup_handler(void *arg) { rtsp_conn_info *conn = (rtsp_conn_info *)arg; close(conn->audio_socket); + debug(3,"Audio Receiver Cleanup Successful."); } void *rtp_audio_receiver(void *arg) { @@ -187,6 +188,7 @@ void *rtp_audio_receiver(void *arg) { void rtp_control_handler_cleanup_handler(void *arg) { rtsp_conn_info *conn = (rtsp_conn_info *)arg; close(conn->control_socket); + debug(3,"Control Receiver Cleanup Successful."); } void *rtp_control_receiver(void *arg) { @@ -470,6 +472,7 @@ void rtp_timing_receiver_cleanup_handler(void *arg) { pthread_cancel(timer_requester); pthread_join(timer_requester, NULL); close(conn->timing_socket); + debug(3,"Timing Receiver Cleanup Successful."); } void *rtp_timing_receiver(void *arg) { From a5e39ffd7e3dac00ff8f44186e34c2313da96e19 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 12:24:06 +0100 Subject: [PATCH 34/44] Update RELEASENOTES.md --- RELEASENOTES.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index d7b96a3e..6d93a95d 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,4 +1,10 @@ +Version 3.2d53 +==== +**Bug Fix** +* Fix an incompatibility with Cygwin 64. It seems that the handling of signals in Cygwin is different to regular "native" Unix/Linux platforms. So, this is an attempt to use `pthread_cancel` calls where possible. In principle it should considerably simplify thread management, so let's see how it goes. +* Fix an off-by-one error that was generating excessive resend requests. + Version 3.2d51 ==== * Fix a small bug locking and unlocking the read-write mutex. It might (and in principle, it could) cause a crash. From 6d08725539302aef3cee431681f36180d8321ffc Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 16:15:17 +0100 Subject: [PATCH 35/44] If the player thread is locked, don't block player_put_packet. Instead, discard the packet. --- player.c | 277 ++++++++++++++++++++++++++++--------------------------- player.h | 2 +- rtp.c | 32 ++----- 3 files changed, 153 insertions(+), 158 deletions(-) diff --git a/player.c b/player.c index 67fac035..2c18fc22 100644 --- a/player.c +++ b/player.c @@ -466,169 +466,176 @@ static void free_audio_buffers(rtsp_conn_info *conn) { void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp, uint8_t *data, int len, rtsp_conn_info *conn) { - pthread_rwlock_rdlock(&conn->player_thread_lock); - if (conn->player_thread != NULL) { + if (pthread_rwlock_tryrdlock(&conn->player_thread_lock) == 0) { + if (conn->player_thread != NULL) { - // all timestamps are done at the output rate - // the "actual_timestamp" is the one that comes in the packet, and is carried over for debugging - // and checking only. + // all timestamps are done at the output rate + // the "actual_timestamp" is the one that comes in the packet, and is carried over for + // debugging + // and checking only. - int64_t ltimestamp = timestamp * conn->output_sample_ratio; + int64_t ltimestamp = timestamp * conn->output_sample_ratio; - // ignore a request to flush that has been made before the first packet... - if (conn->packet_count == 0) { - pthread_mutex_lock(&conn->flush_mutex); - conn->flush_requested = 0; - conn->flush_rtp_timestamp = 0; - pthread_mutex_unlock(&conn->flush_mutex); - } + // ignore a request to flush that has been made before the first packet... + if (conn->packet_count == 0) { + pthread_mutex_lock(&conn->flush_mutex); + conn->flush_requested = 0; + conn->flush_rtp_timestamp = 0; + pthread_mutex_unlock(&conn->flush_mutex); + } - pthread_mutex_lock(&conn->ab_mutex); - conn->packet_count++; - conn->time_of_last_audio_packet = get_absolute_time_in_fp(); - if (conn->connection_state_to_output) { // if we are supposed to be processing these packets + pthread_mutex_lock(&conn->ab_mutex); + conn->packet_count++; + conn->time_of_last_audio_packet = get_absolute_time_in_fp(); + if (conn->connection_state_to_output) { // if we are supposed to be processing these packets - // if (flush_rtp_timestamp != 0) - // debug(1,"Flush_rtp_timestamp is %u",flush_rtp_timestamp); + // if (flush_rtp_timestamp != 0) + // debug(1,"Flush_rtp_timestamp is %u",flush_rtp_timestamp); - if ((conn->flush_rtp_timestamp != 0) && (ltimestamp <= conn->flush_rtp_timestamp)) { - debug(3, + if ((conn->flush_rtp_timestamp != 0) && (ltimestamp <= conn->flush_rtp_timestamp)) { + debug( + 3, "Dropping flushed packet in player_put_packet, seqno %u, timestamp %lld, flushing to " "timestamp: %lld.", seqno, ltimestamp, conn->flush_rtp_timestamp); - } else { - if ((conn->flush_rtp_timestamp != 0x0) && - (ltimestamp > - conn->flush_rtp_timestamp)) // if we have gone past the flush boundary time - conn->flush_rtp_timestamp = 0x0; + } else { + if ((conn->flush_rtp_timestamp != 0x0) && + (ltimestamp > + conn->flush_rtp_timestamp)) // if we have gone past the flush boundary time + conn->flush_rtp_timestamp = 0x0; - abuf_t *abuf = 0; + abuf_t *abuf = 0; - if (!conn->ab_synced) { - debug(3, "syncing to seqno %u.", seqno); - conn->ab_write = seqno; - conn->ab_read = seqno; - conn->ab_synced = 1; - } + if (!conn->ab_synced) { + debug(3, "syncing to seqno %u.", seqno); + conn->ab_write = seqno; + conn->ab_read = seqno; + conn->ab_synced = 1; + } - // here, we should check for missing frames - int resend_interval = (((250 * 44100) / 352) / 1000); // approximately 250 ms intervals - const int number_of_resend_attempts = 8; - int latency_based_resend_interval = - (conn->latency) / (number_of_resend_attempts * conn->max_frames_per_packet); - if (latency_based_resend_interval > resend_interval) - resend_interval = latency_based_resend_interval; + // here, we should check for missing frames + int resend_interval = (((250 * 44100) / 352) / 1000); // approximately 250 ms intervals + const int number_of_resend_attempts = 8; + int latency_based_resend_interval = + (conn->latency) / (number_of_resend_attempts * conn->max_frames_per_packet); + if (latency_based_resend_interval > resend_interval) + resend_interval = latency_based_resend_interval; - if (conn->resend_interval != resend_interval) { - debug(2, "Resend interval for latency of %" PRId64 " frames is %d frames.", conn->latency, - resend_interval); - conn->resend_interval = resend_interval; - } - if (!conn->ab_buffering) { - int j; - for (j = 1; j <= number_of_resend_attempts; j++) { - // check j times, after a short period of has elapsed, assuming 352 frames per packet + if (conn->resend_interval != resend_interval) { + debug(2, "Resend interval for latency of %" PRId64 " frames is %d frames.", + conn->latency, resend_interval); + conn->resend_interval = resend_interval; + } + if (!conn->ab_buffering) { + int j; + for (j = 1; j <= number_of_resend_attempts; j++) { + // check j times, after a short period of has elapsed, assuming 352 frames per packet - int back_step = resend_interval * j; + int back_step = resend_interval * j; - int32_t sd = seq_diff(conn->ab_read, conn->ab_write, conn->ab_read); - int k; - for (k = -2; k <= 2; k++) { - if ((back_step + k) < sd) { // if it's within the range of frames in use... - int item_to_check = (conn->ab_write - (back_step + k)) & 0xffff; - seq_t next = item_to_check; - abuf_t *check_buf = conn->audio_buffer + BUFIDX(next); - if ((!check_buf->ready) && - (check_buf->resend_level < - j)) { // prevent multiple requests from the same level of lookback - check_buf->resend_level = j; - if (config.disable_resend_requests == 0) { - rtp_request_resend(next, 1, conn); - if ((back_step + k + resend_interval) >= sd) - debug(2, "Last-ditch (#%d) resend request for packet %u in range %u to %u. " - "Looking back %d packets.", - j, next, conn->ab_read, conn->ab_write, back_step + k); - conn->resend_requests++; + int32_t sd = seq_diff(conn->ab_read, conn->ab_write, conn->ab_read); + int k; + for (k = -2; k <= 2; k++) { + if ((back_step + k) < sd) { // if it's within the range of frames in use... + int item_to_check = (conn->ab_write - (back_step + k)) & 0xffff; + seq_t next = item_to_check; + abuf_t *check_buf = conn->audio_buffer + BUFIDX(next); + if ((!check_buf->ready) && + (check_buf->resend_level < + j)) { // prevent multiple requests from the same level of lookback + check_buf->resend_level = j; + if (config.disable_resend_requests == 0) { + rtp_request_resend(next, 1, conn); + if ((back_step + k + resend_interval) >= sd) + debug(2, "Last-ditch (#%d) resend request for packet %u in range %u to %u. " + "Looking back %d packets.", + j, next, conn->ab_read, conn->ab_write, back_step + k); + conn->resend_requests++; + } } } } } } - } - if (conn->ab_write == seqno) { // expected packet - abuf = conn->audio_buffer + BUFIDX(seqno); - conn->ab_write = SUCCESSOR(seqno); - } else if (seq_order(conn->ab_write, seqno, conn->ab_read)) { // newer than expected - // if (ORDINATE(seqno)>(BUFFER_FRAMES*7)/8) - // debug(1,"An interval of %u frames has opened, with ab_read: %u, ab_write: %u and seqno: - // %u.",seq_diff(ab_read,seqno),ab_read,ab_write,seqno); - int32_t gap = seq_diff(conn->ab_write, seqno, conn->ab_read); - if (gap <= 0) - debug(1, "Unexpected gap size: %d.", gap); - int i; - for (i = 0; i < gap; i++) { - abuf = conn->audio_buffer + BUFIDX(seq_sum(conn->ab_write, i)); - abuf->ready = 0; // to be sure, to be sure - abuf->resend_level = 0; - abuf->timestamp = 0; - abuf->given_timestamp = 0; - abuf->sequence_number = 0; + if (conn->ab_write == seqno) { // expected packet + abuf = conn->audio_buffer + BUFIDX(seqno); + conn->ab_write = SUCCESSOR(seqno); + } else if (seq_order(conn->ab_write, seqno, conn->ab_read)) { // newer than expected + // if (ORDINATE(seqno)>(BUFFER_FRAMES*7)/8) + // debug(1,"An interval of %u frames has opened, with ab_read: %u, ab_write: %u and + // seqno: + // %u.",seq_diff(ab_read,seqno),ab_read,ab_write,seqno); + int32_t gap = seq_diff(conn->ab_write, seqno, conn->ab_read); + if (gap <= 0) + debug(1, "Unexpected gap size: %d.", gap); + int i; + for (i = 0; i < gap; i++) { + abuf = conn->audio_buffer + BUFIDX(seq_sum(conn->ab_write, i)); + abuf->ready = 0; // to be sure, to be sure + abuf->resend_level = 0; + abuf->timestamp = 0; + abuf->given_timestamp = 0; + abuf->sequence_number = 0; + } + // debug(1,"N %d s %u.",seq_diff(ab_write,PREDECESSOR(seqno))+1,ab_write); + abuf = conn->audio_buffer + BUFIDX(seqno); + // rtp_request_resend(ab_write, gap); + // resend_requests++; + conn->ab_write = SUCCESSOR(seqno); + } else if (seq_order(conn->ab_read, seqno, conn->ab_read)) { // late but not yet played + conn->late_packets++; + abuf = conn->audio_buffer + BUFIDX(seqno); + /* + if (abuf->ready) + debug(1,"Late apparently duplicate packet received that is %d packets + late.",seq_diff(seqno, conn->ab_write, conn->ab_read)); + else + debug(1,"Late packet received that is %d packets late.",seq_diff(seqno, + conn->ab_write, conn->ab_read)); + */ + } else { // too late. + + // debug(1,"Too late packet received that is %d packets late.",seq_diff(seqno, + // conn->ab_write, conn->ab_read)); + conn->too_late_packets++; } - // debug(1,"N %d s %u.",seq_diff(ab_write,PREDECESSOR(seqno))+1,ab_write); - abuf = conn->audio_buffer + BUFIDX(seqno); - // rtp_request_resend(ab_write, gap); - // resend_requests++; - conn->ab_write = SUCCESSOR(seqno); - } else if (seq_order(conn->ab_read, seqno, conn->ab_read)) { // late but not yet played - conn->late_packets++; - abuf = conn->audio_buffer + BUFIDX(seqno); - /* - if (abuf->ready) - debug(1,"Late apparently duplicate packet received that is %d packets - late.",seq_diff(seqno, conn->ab_write, conn->ab_read)); - else - debug(1,"Late packet received that is %d packets late.",seq_diff(seqno, - conn->ab_write, conn->ab_read)); - */ - } else { // too late. + // pthread_mutex_unlock(&ab_mutex); - // debug(1,"Too late packet received that is %d packets late.",seq_diff(seqno, - // conn->ab_write, conn->ab_read)); - conn->too_late_packets++; - } - // pthread_mutex_unlock(&ab_mutex); - - if (abuf) { - int datalen = conn->max_frames_per_packet; - if (alac_decode(abuf->data, &datalen, data, len, conn) == 0) { - abuf->ready = 1; - abuf->length = datalen; - abuf->timestamp = ltimestamp; - abuf->given_timestamp = actual_timestamp; - abuf->sequence_number = seqno; - } else { - debug(1, "Bad audio packet detected and discarded."); - abuf->ready = 0; - abuf->resend_level = 0; - abuf->timestamp = 0; - abuf->given_timestamp = 0; - abuf->sequence_number = 0; + if (abuf) { + int datalen = conn->max_frames_per_packet; + if (alac_decode(abuf->data, &datalen, data, len, conn) == 0) { + abuf->ready = 1; + abuf->length = datalen; + abuf->timestamp = ltimestamp; + abuf->given_timestamp = actual_timestamp; + abuf->sequence_number = seqno; + } else { + debug(1, "Bad audio packet detected and discarded."); + abuf->ready = 0; + abuf->resend_level = 0; + abuf->timestamp = 0; + abuf->given_timestamp = 0; + abuf->sequence_number = 0; + } } - } - // pthread_mutex_lock(&ab_mutex); + // pthread_mutex_lock(&ab_mutex); + } + int rc = pthread_cond_signal(&conn->flowcontrol); + if (rc) + debug(1, "Error signalling flowcontrol."); } - int rc = pthread_cond_signal(&conn->flowcontrol); - if (rc) - debug(1, "Error signalling flowcontrol."); - } - pthread_mutex_unlock(&conn->ab_mutex); - } else { - debug(1, + pthread_mutex_unlock(&conn->ab_mutex); + } else { + debug( + 1, "No player thread while adding a player_put_packet calle was made -- packet discarded."); + } + pthread_rwlock_unlock(&conn->player_thread_lock); + } else { + debug(1, "player_put_packet discarded packet %d because the player thread was locked.", seqno); } - pthread_rwlock_unlock(&conn->player_thread_lock); } int32_t rand_in_range(int32_t exclusive_range_limit) { diff --git a/player.h b/player.h index eb8046e6..793413ba 100644 --- a/player.h +++ b/player.h @@ -81,7 +81,7 @@ typedef struct { SOCKADDR remote, local; int stop; int running; - pthread_t thread; + pthread_t thread, timer_requester; // pthread_t *ptp; pthread_t *player_thread; diff --git a/rtp.c b/rtp.c index cecae3e7..d7ad617f 100644 --- a/rtp.c +++ b/rtp.c @@ -66,9 +66,10 @@ void rtp_terminate(rtsp_conn_info *conn) { } void rtp_audio_receiver_cleanup_handler(void *arg) { + debug(2, "Audio Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; close(conn->audio_socket); - debug(3,"Audio Receiver Cleanup Successful."); + debug(2, "Audio Receiver Cleanup Successful."); } void *rtp_audio_receiver(void *arg) { @@ -90,7 +91,6 @@ void *rtp_audio_receiver(void *arg) { ssize_t nread; while (1) { - nread = recv(conn->audio_socket, packet, sizeof(packet), 0); uint64_t local_time_now_fp = get_absolute_time_in_fp(); @@ -186,9 +186,10 @@ void *rtp_audio_receiver(void *arg) { } void rtp_control_handler_cleanup_handler(void *arg) { + debug(2, "Control Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; close(conn->control_socket); - debug(3,"Control Receiver Cleanup Successful."); + debug(2, "Control Receiver Cleanup Successful."); } void *rtp_control_receiver(void *arg) { @@ -465,14 +466,13 @@ void *rtp_timing_sender(void *arg) { pthread_exit(NULL); } -pthread_t timer_requester; - void rtp_timing_receiver_cleanup_handler(void *arg) { + debug(2, "Timing Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; - pthread_cancel(timer_requester); - pthread_join(timer_requester, NULL); + pthread_cancel(conn->timer_requester); + pthread_join(conn->timer_requester, NULL); close(conn->timing_socket); - debug(3,"Timing Receiver Cleanup Successful."); + debug(2, "Timing Receiver Cleanup Successful."); } void *rtp_timing_receiver(void *arg) { @@ -481,7 +481,7 @@ void *rtp_timing_receiver(void *arg) { uint8_t packet[2048]; ssize_t nread; - pthread_create(&timer_requester, NULL, &rtp_timing_sender, arg); + pthread_create(&conn->timer_requester, NULL, &rtp_timing_sender, arg); // struct timespec att; uint64_t distant_receive_time, distant_transmit_time, arrival_time, return_time; local_to_remote_time_jitters = 0; @@ -521,7 +521,7 @@ void *rtp_timing_receiver(void *arg) { return_time = arrival_time - conn->departure_time; - //uint64_t rtus = (return_time * 1000000) >> 32; + // uint64_t rtus = (return_time * 1000000) >> 32; if (((return_time * 1000000) >> 32) < 300000) { @@ -760,18 +760,6 @@ static uint16_t bind_port(int ip_family, const char *self_ip_address, uint32_t s struct sockaddr_in *sa = (struct sockaddr_in *)&local; sport = ntohs(sa->sin_port); } - // fcntl(local_socket, F_SETFL, O_NONBLOCK); - - // don't wait if outputting something will take longer than this time. - struct timeval timeout; - timeout.tv_sec = 0; - timeout.tv_usec = 2000; // two milliseconds - - if (setsockopt(local_socket, SOL_SOCKET, SO_SNDTIMEO, (char *)&timeout, sizeof(timeout)) < 0) - debug(1, "bind_port set output timeout failed."); - // else - // debug(1,"bind_port set output timeout succeeded."); - *sock = local_socket; return sport; } From 9d43064bfd1c7b9afde157c5365075776b1e1201 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 16:15:52 +0100 Subject: [PATCH 36/44] If the player thread is locked, don't block player_put_packet. Instead, discard the packet. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 70e5fa0a..06ac2ec0 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d53], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d54], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From b25415ce01e757c0c524672601dc12dc52f7e036 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Thu, 17 May 2018 16:42:55 +0100 Subject: [PATCH 37/44] Update RELEASENOTES.md --- RELEASENOTES.md | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index 6d93a95d..7510d75c 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,4 +1,9 @@ +Version 3.2d54 +==== +**Bug Fix** +* Prevent packets of audio being added when the play session has ended and the play thread is being deleted. They are now simply dropped. + Version 3.2d53 ==== **Bug Fix** From 8f9aaf721185636267d7e7177aa6c3968bb0b15f Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 08:33:21 +0100 Subject: [PATCH 38/44] Drop a player_flush request if a read lock can't be acquired on the player thread. --- player.c | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/player.c b/player.c index 2c18fc22..ca24cfac 100644 --- a/player.c +++ b/player.c @@ -2637,12 +2637,15 @@ void do_flush(int64_t timestamp, rtsp_conn_info *conn) { void player_flush(int64_t timestamp, rtsp_conn_info *conn) { debug(3, "player_flush"); - pthread_rwlock_rdlock(&conn->player_thread_lock); - if (conn->player_thread != NULL) - do_flush(timestamp, conn); - else - debug(1, "Flush requested when player thread is gone."); - pthread_rwlock_unlock(&conn->player_thread_lock); + if (pthread_rwlock_tryrdlock(&conn->player_thread_lock) == 0) { + if (conn->player_thread != NULL) + do_flush(timestamp, conn); + else + debug(1, "Flush requested when player thread is gone."); + pthread_rwlock_unlock(&conn->player_thread_lock); + } else { + debug(3, "Can't acquire a read lock for a flush -- ignored."); + } } int player_play(rtsp_conn_info *conn) { From ba59ea96044651d614c626e2d2f1e1064eec8bf1 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 08:34:30 +0100 Subject: [PATCH 39/44] Drop a player_flush request if a read lock can't be acquired on the player thread. --- configure.ac | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/configure.ac b/configure.ac index 06ac2ec0..d954b771 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [3.2d54], [mikebrady@eircom.net]) +AC_INIT([shairport-sync], [3.2d55], [mikebrady@eircom.net]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) From d967bfc7ed3d17a41a7f9f018a64fbb5ee892099 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 08:39:16 +0100 Subject: [PATCH 40/44] Update RELEASENOTES.md --- RELEASENOTES.md | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index 7510d75c..e3f85b01 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -1,4 +1,9 @@ +Version 3.2d55 +==== +**Bug Fix** +* Flush requests that are received while the player is being initialised or deleted are now ignored. This should prevents two potential (but never seen) lock possibilities. + Version 3.2d54 ==== **Bug Fix** @@ -7,7 +12,7 @@ Version 3.2d54 Version 3.2d53 ==== **Bug Fix** -* Fix an incompatibility with Cygwin 64. It seems that the handling of signals in Cygwin is different to regular "native" Unix/Linux platforms. So, this is an attempt to use `pthread_cancel` calls where possible. In principle it should considerably simplify thread management, so let's see how it goes. +* Fix an incompatibility with Cygwin 64. It seems that the handling of signals in Cygwin is different to regular "native" Unix/Linux platforms. So, this is an attempt to use `pthread_cancel` calls where possible. In principle it should simplify thread management considerably, so let's see how it goes. * Fix an off-by-one error that was generating excessive resend requests. Version 3.2d51 From dfba17a4e2d59b7156d1427ddeb7ac5e63d83e2a Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 08:42:32 +0100 Subject: [PATCH 41/44] Update README.md --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 4ee3549d..818cd66f 100644 --- a/README.md +++ b/README.md @@ -2,7 +2,7 @@ Shairport Sync ============= Shairport Sync is an AirPlay audio player – it plays audio streamed from iTunes, iOS, Apple TV and macOS devices and AirPlay sources such as Quicktime Player and [ForkedDaapd](http://ejurgensen.github.io/forked-daapd/), among others. -Audio played by a Shairport Sync-powered device stays synchronised with the source and hence with similar devices playing the same source. In this way, synchronised multi-room audio is possible for players such as iTunes. Shairport Sync does not support multi-room audio for iOS devices. +Audio played by a Shairport Sync-powered device stays synchronised with the source and hence with similar devices playing the same source. In this way, synchronised multi-room audio is possible for players that support it, such as iTunes. Shairport Sync runs on Linux and FreeBSD. It does not support AirPlay video or photo streaming. From 499fae9796f13017dc97a625bd1db087bb44fe83 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 10:08:01 +0100 Subject: [PATCH 42/44] Tidy up and quieten some debug messages. --- rtp.c | 18 +++++++++--------- rtsp.c | 28 ++++++++++++++-------------- 2 files changed, 23 insertions(+), 23 deletions(-) diff --git a/rtp.c b/rtp.c index d7ad617f..d0f1d1af 100644 --- a/rtp.c +++ b/rtp.c @@ -66,10 +66,10 @@ void rtp_terminate(rtsp_conn_info *conn) { } void rtp_audio_receiver_cleanup_handler(void *arg) { - debug(2, "Audio Receiver Cleanup."); + debug(3, "Audio Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; close(conn->audio_socket); - debug(2, "Audio Receiver Cleanup Successful."); + debug(3, "Audio Receiver Cleanup Successful."); } void *rtp_audio_receiver(void *arg) { @@ -186,10 +186,10 @@ void *rtp_audio_receiver(void *arg) { } void rtp_control_handler_cleanup_handler(void *arg) { - debug(2, "Control Receiver Cleanup."); + debug(3, "Control Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; close(conn->control_socket); - debug(2, "Control Receiver Cleanup Successful."); + debug(3, "Control Receiver Cleanup Successful."); } void *rtp_control_receiver(void *arg) { @@ -462,17 +462,17 @@ void *rtp_timing_sender(void *arg) { else usleep(3000000); } - debug(3, "rtp_timing_sender thread interrupted. terminating."); + debug(3, "rtp_timing_sender thread interrupted. This should never happen."); pthread_exit(NULL); } void rtp_timing_receiver_cleanup_handler(void *arg) { - debug(2, "Timing Receiver Cleanup."); + debug(3, "Timing Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; pthread_cancel(conn->timer_requester); pthread_join(conn->timer_requester, NULL); close(conn->timing_socket); - debug(2, "Timing Receiver Cleanup Successful."); + debug(3, "Timing Receiver Cleanup Successful."); } void *rtp_timing_receiver(void *arg) { @@ -812,8 +812,8 @@ void rtp_setup(SOCKADDR *local, SOCKADDR *remote, uint16_t cport, uint16_t tport inet_ntop(conn->connection_ip_family, self_addr, conn->self_ip_string, sizeof(conn->self_ip_string)); - debug(2, "SETUP connection from %s to self at %s on RTSP conversation thread %d.", - conn->client_ip_string, conn->self_ip_string, conn->connection_number); + debug(2, "Connection %d: SETUP -- Connection from %s to self at %s.", + conn->connection_number,conn->client_ip_string, conn->self_ip_string); // set up a the record of the remote's control socket struct addrinfo hints; diff --git a/rtsp.c b/rtsp.c index 8366069c..a0e79118 100644 --- a/rtsp.c +++ b/rtsp.c @@ -762,12 +762,12 @@ 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(2, "Connection %d: SETUP", conn->connection_number); + debug(3, "Connection %d: SETUP", conn->connection_number); uint16_t cport, tport; char *ar = msg_get_header(req, "Active-Remote"); if (ar) { - debug(2, "Active-Remote string seen: \"%s\".", ar); + debug(2, "Connection %d: SETUP -- Active-Remote string seen: \"%s\".", conn->connection_number, ar); // get the active remote char *p; conn->dacp_active_remote = strtoul(ar, &p, 10); @@ -775,13 +775,13 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message * send_metadata('ssnc', 'acre', ar, strlen(ar), req, 1); #endif } else { - debug(2, "Note: no Active-Remote information the SETUP Record."); + debug(2, "Connection %d: SETUP -- Note: no Active-Remote information the SETUP Record.",conn->connection_number); conn->dacp_active_remote = 0; } ar = msg_get_header(req, "DACP-ID"); if (ar) { - debug(2, "DACP-ID string seen: \"%s\".", ar); + debug(2, "Connection %d: SETUP -- DACP-ID string seen: \"%s\".",conn->connection_number, ar); if (conn->dacp_id) // this is in case SETUP was previously called free(conn->dacp_id); conn->dacp_id = strdup(ar); @@ -789,7 +789,7 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message * send_metadata('ssnc', 'daid', ar, strlen(ar), req, 1); #endif } else { - debug(2, "Note: no DACP-ID string information in the SETUP Record."); + debug(2, "Connection %d: SETUP doesn't include DACP-ID string information.",conn->connection_number); if (conn->dacp_id) // this is in case SETUP was previously called free(conn->dacp_id); conn->dacp_id = NULL; @@ -797,14 +797,14 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message * char *hdr = msg_get_header(req, "Transport"); if (!hdr) { - debug(1, "SETUP doesn't contain a Transport header."); + debug(1, "Connection %d: SETUP doesn't contain a Transport header.",conn->connection_number); goto error; } char *p; p = strstr(hdr, "control_port="); if (!p) { - debug(1, "SETUP doesn't specify a control_port."); + debug(1, "Connection %d: SETUP doesn't specify a control_port.",conn->connection_number); goto error; } p = strchr(p, '=') + 1; @@ -812,7 +812,7 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message * p = strstr(hdr, "timing_port="); if (!p) { - debug(1, "SETUP doesn't specify a timing_port."); + debug(1, "Connection %d: SETUP doesn't specify a timing_port.",conn->connection_number); goto error; } p = strchr(p, '=') + 1; @@ -820,19 +820,19 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message * if (conn->rtp_running) { if ((conn->remote_control_port != cport) || (conn->remote_timing_port != tport)) { - warn("Duplicate SETUP message with different control (old %u, new %u) or timing (old %u, new " - "%u) ports! This is probably fatal!", + warn("Connection %d: Duplicate SETUP message with different control (old %u, new %u) or timing (old %u, new " + "%u) ports! This is probably fatal!",conn->connection_number, conn->remote_control_port, cport, conn->remote_timing_port, tport); } else { - warn("Duplicate SETUP message with the same control (%u) and timing (%u) ports. This is " - "probably not fatal.", + warn("Connection %d: Duplicate SETUP message with the same control (%u) and timing (%u) ports. This is " + "probably not fatal.",conn->connection_number, conn->remote_control_port, conn->remote_timing_port); } } else { rtp_setup(&conn->local, &conn->remote, cport, tport, conn); } if (conn->local_audio_port == 0) { - debug(1, "SETUP seems to specify a null audio port."); + debug(1, "Connection %d: SETUP seems to specify a null audio port.",conn->connection_number); goto error; } @@ -851,7 +851,7 @@ static void handle_setup(rtsp_conn_info *conn, rtsp_message *req, rtsp_message * return; error: - warn("Error in setup request -- unlocking play lock on RTSP conversation thread %d.", + warn("Connection %d: SETUP -- Error in setup request -- unlocking play lock.", conn->connection_number); playing_conn = NULL; pthread_mutex_unlock(&play_lock); From 7830fa6542cd88e35ba09076356eab97e269c7e6 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 10:19:23 +0100 Subject: [PATCH 43/44] Update RELEASENOTES.md --- RELEASENOTES.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/RELEASENOTES.md b/RELEASENOTES.md index e3f85b01..441ba883 100644 --- a/RELEASENOTES.md +++ b/RELEASENOTES.md @@ -7,7 +7,7 @@ Version 3.2d55 Version 3.2d54 ==== **Bug Fix** -* Prevent packets of audio being added when the play session has ended and the play thread is being deleted. They are now simply dropped. +* Prevent packets of audio being added when the play session has ended and the player is being deleted. They are now simply dropped. Version 3.2d53 ==== From 3fbd47ad058e9a5d04cf4b7661c50646982afaf8 Mon Sep 17 00:00:00 2001 From: Mike Brady Date: Fri, 18 May 2018 15:22:20 +0100 Subject: [PATCH 44/44] Fix minor warnings from some of the backend modules and make the configure messages a little more helpful. --- audio_dummy.c | 2 +- audio_sndio.c | 4 ++-- audio_soundio.c | 4 ++-- audio_stdout.c | 2 +- configure.ac | 4 ++-- 5 files changed, 8 insertions(+), 8 deletions(-) diff --git a/audio_dummy.c b/audio_dummy.c index b0163de7..5f55bab1 100644 --- a/audio_dummy.c +++ b/audio_dummy.c @@ -48,7 +48,7 @@ static void start(int sample_rate, __attribute__((unused)) int sample_format) { debug(1, "dummy audio output started at Fs=%d Hz\n", sample_rate); } -static void play(__attribute__((unused)) short buf[], __attribute__((unused)) int samples) {} +static void play(__attribute__((unused)) void *buf, __attribute__((unused)) int samples) {} static void stop(void) { debug(1, "dummy audio stopped\n"); } diff --git a/audio_sndio.c b/audio_sndio.c index 119e84e1..d9cef65e 100644 --- a/audio_sndio.c +++ b/audio_sndio.c @@ -33,7 +33,7 @@ static int init(int, char **); static void onmove_cb(void *, int); static void deinit(void); static void start(int, int); -static void play(short[], int); +static void play(void *, int); static void stop(void); static void onmove_cb(void *, int); static int delay(long *); @@ -222,7 +222,7 @@ static void start(__attribute__((unused)) int sample_rate, pthread_mutex_unlock(&sndio_mutex); } -static void play(short buf[], int frames) { +static void play(void *buf, int frames) { if (frames > 0) { pthread_mutex_lock(&sndio_mutex); written += sio_write(hdl, buf, frames * framesize); diff --git a/audio_soundio.c b/audio_soundio.c index 1012ec6e..c46e00d5 100644 --- a/audio_soundio.c +++ b/audio_soundio.c @@ -167,7 +167,7 @@ static void start(int sample_rate, int sample_format) { debug(1, "libsoundio output started\n"); } -static void play(short buf[], int samples) { +static void play(void *buf, int samples) { // int err; int free_bytes = soundio_ring_buffer_free_count(ring_buffer); int written_bytes = 0; @@ -181,7 +181,7 @@ static void play(short buf[], int samples) { free_bytes); if (write_bytes) { - memcpy(write_ptr, (char *)buf, write_bytes); + memcpy(write_ptr, buf, write_bytes); written_bytes += write_bytes; soundio_ring_buffer_advance_write_ptr(ring_buffer, write_bytes); debug(3, "[<<---] Written to buffer : %d\n", written_bytes); diff --git a/audio_stdout.c b/audio_stdout.c index 35399945..3e27ad15 100644 --- a/audio_stdout.c +++ b/audio_stdout.c @@ -43,7 +43,7 @@ static void start(__attribute__((unused)) int sample_rate, fd = STDOUT_FILENO; } -static void play(short buf[], int samples) { +static void play(void *buf, int samples) { char errorstring[1024]; int warned = 0; int rc = write(fd, buf, samples * 4); diff --git a/configure.ac b/configure.ac index d954b771..601403ba 100644 --- a/configure.ac +++ b/configure.ac @@ -225,7 +225,7 @@ AC_ARG_WITH(sndio, [ --with-sndio = choose SNDIO API support], [ AC_MSG_RESULT(>>Including a SNDIO back end) HAS_SNDIO=1 AC_DEFINE([CONFIG_SNDIO], 1, [Needed by the compiler.]) - AC_CHECK_LIB([sndio], [sio_open], , AC_MSG_ERROR(SNDIO support requires the sndio library!))], ) + AC_CHECK_LIB([sndio], [sio_open], , AC_MSG_ERROR(SNDIO support requires the sndio library -- libsndio-dev suggested))], ) AM_CONDITIONAL([USE_SNDIO], [test "x$HAS_SNDIO" = "x1"]) # Look for AO flag @@ -241,7 +241,7 @@ AC_ARG_WITH(soundio, [ --with-soundio = choose soundio API support.], [ AC_MSG_RESULT(>>Including an soundio back end) HAS_SOUNDIO=1 AC_DEFINE([CONFIG_SOUNDIO], 1, [Needed by the compiler.]) - AC_CHECK_LIB([soundio], [soundio_create], , AC_MSG_ERROR(soundio support requires the soundio library!))], ) + AC_CHECK_LIB([soundio], [soundio_create], , AC_MSG_ERROR(soundio support requires the soundio library -- libsoundio-dev suggested))], ) AM_CONDITIONAL([USE_SOUNDIO], [test "x$HAS_SOUNDIO" = "x1"]) # Look for pulseaudio flag