Add the ability to call a program if an unfixable error is detected. The only unfixialbe error at present is then a play session can't be cancelled.

Merge branch 'more_danger' into development

audio_alsa.c

@@ -74,11 +74,13 @@ audio_output audio_alsa = {
 
 static pthread_mutex_t alsa_mutex = PTHREAD_MUTEX_INITIALIZER;
 
+static snd_output_t *output = NULL;
 static unsigned int desired_sample_rate;
 static enum sps_format_t sample_format;
 
 static snd_pcm_t *alsa_handle = NULL;
 static snd_pcm_hw_params_t *alsa_params = NULL;
+static snd_pcm_sw_params_t *alsa_swparams = NULL;
 static snd_ctl_t *ctl = NULL;
 static snd_ctl_elem_id_t *elem_id = NULL;
 static snd_mixer_t *alsa_mix_handle = NULL;
@@ -134,6 +136,7 @@ static void help(void) {
 
 void set_alsa_out_dev(char *dev) { alsa_out_dev = dev; }
 
+// assuming pthread cancellation is disabled
 int open_mixer() {
   int response = 0;
   if (hardware_mixer) {
@@ -177,6 +180,7 @@ int open_mixer() {
   return response;
 }
 
+// assuming pthread cancellation is disabled
 void close_mixer() {
   if (alsa_mix_handle) {
     snd_mixer_close(alsa_mix_handle);
@@ -184,6 +188,7 @@ void close_mixer() {
   }
 }
 
+// assuming pthread cancellation is disabled
 void do_snd_mixer_selem_set_playback_dB_all(snd_mixer_elem_t *mix_elem, double vol) {
   if (snd_mixer_selem_set_playback_dB_all(mix_elem, vol, 0) != 0) {
     debug(1, "Can't set playback volume accurately to %f dB.", vol);
@@ -194,6 +199,9 @@ void do_snd_mixer_selem_set_playback_dB_all(snd_mixer_elem_t *mix_elem, double v
 }
 
 static int init(int argc, char **argv) {
+  // for debugging
+  snd_output_stdio_attach(&output, stdout, 0);
+
   // debug(2,"audio_alsa init called.");
   int response = 0; // this will be what we return to the caller.
   const char *str;
@@ -405,6 +413,8 @@ static int init(int argc, char **argv) {
   debug(1, "alsa: output device name is \"%s\".", alsa_out_dev);
 
   if (hardware_mixer) {
+    int oldState;
+    pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
 
     if (alsa_mix_dev == NULL)
       alsa_mix_dev = alsa_out_dev;
@@ -491,6 +501,7 @@ static int init(int argc, char **argv) {
     }
     debug_mutex_unlock(&alsa_mutex, 3); // release the mutex
     pthread_cleanup_pop(0);
+    pthread_setcancelstate(oldState, NULL);
   } else {
     debug(1, "alsa: no hardware mixer selected.");
   }
@@ -504,7 +515,8 @@ static void deinit(void) {
   stop();
 }
 
-int open_alsa_device(void) {
+// assuming pthread cancellation is disabled
+int actual_open_alsa_device(void) {
   // the alsa mutex is already acquired when this is called
   const snd_pcm_uframes_t minimal_buffer_headroom =
       352 * 2; // we accept this much headroom in the hardware buffer, but we'll
@@ -536,6 +548,7 @@ int open_alsa_device(void) {
     return (-10);
 
   snd_pcm_hw_params_alloca(&alsa_params);
+  snd_pcm_sw_params_alloca(&alsa_swparams);
 
   ret = snd_pcm_hw_params_any(alsa_handle, alsa_params);
   if (ret < 0) {
@@ -692,6 +705,28 @@ int open_alsa_device(void) {
     return -9;
   }
 
+  ret = snd_pcm_sw_params_current(alsa_handle, alsa_swparams);
+  if (ret < 0) {
+    warn("audio_alsa: Unable to get current sw parameters for device \"%s\": %s.", alsa_out_dev,
+         snd_strerror(ret));
+    return -10;
+  }
+
+  ret = snd_pcm_sw_params_set_tstamp_mode(alsa_handle, alsa_swparams, SND_PCM_TSTAMP_ENABLE);
+  if (ret < 0) {
+    warn("audio_alsa: Can't enable timestamp mode of device: \"%s\": %s.", alsa_out_dev,
+         snd_strerror(ret));
+    return -11;
+  }
+
+  /* write the sw parameters */
+  ret = snd_pcm_sw_params(alsa_handle, alsa_swparams);
+  if (ret < 0) {
+    warn("audio_alsa: Unable to set software parameters of device: \"%s\": %s.", alsa_out_dev,
+         snd_strerror(ret));
+    return -12;
+  }
+
   if (actual_buffer_length < config.audio_backend_buffer_desired_length + minimal_buffer_headroom) {
     /*
     // the dac buffer is too small, so let's try to set it
@@ -847,10 +882,18 @@ int open_alsa_device(void) {
       break;
     }
   }
-
   return 0;
 }
 
+int open_alsa_device(void) {
+  int result;
+  int oldState;
+  pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
+  result = actual_open_alsa_device();
+  pthread_setcancelstate(oldState, NULL);
+  return result;
+}
+
 static void start(int i_sample_rate, int i_sample_format) {
   // debug(2,"audio_alsa start called.");
   if (i_sample_rate == 0)
@@ -867,6 +910,43 @@ static void start(int i_sample_rate, int i_sample_format) {
   measurement_data_is_valid = 0;
 }
 
+// assuming pthread cancellation is disabled
+int my_snd_pcm_delay(snd_pcm_t *pcm, snd_pcm_sframes_t *delayp) {
+  int ret;
+  snd_pcm_status_t *alsa_snd_pcm_status;
+  snd_pcm_status_alloca(&alsa_snd_pcm_status);
+
+  struct timespec tn;                // time now
+  snd_htimestamp_t update_timestamp; // actually a struct timespec
+
+  ret = snd_pcm_status(pcm, alsa_snd_pcm_status);
+  if (ret) {
+    *delayp = 0;
+    return ret;
+  }
+
+  snd_pcm_state_t state = snd_pcm_status_get_state(alsa_snd_pcm_status);
+  if (state != SND_PCM_STATE_RUNNING) {
+    *delayp = 0;
+    return -EIO; // might be a better code than this...
+  }
+
+  clock_gettime(CLOCK_MONOTONIC, &tn);
+  snd_pcm_status_get_htstamp(alsa_snd_pcm_status, &update_timestamp);
+
+  uint64_t t1 = tn.tv_sec * (uint64_t)1000000000 + tn.tv_nsec;
+  uint64_t t2 = update_timestamp.tv_sec * (uint64_t)1000000000 + update_timestamp.tv_nsec;
+  uint64_t delta = t1 - t2;
+
+  uint64_t frames_played_since_last_interrupt =
+      ((uint64_t)desired_sample_rate * delta) / 1000000000;
+  snd_pcm_sframes_t frames_played_since_last_interrupt_sized = frames_played_since_last_interrupt;
+
+  *delayp =
+      snd_pcm_status_get_delay(alsa_snd_pcm_status) - frames_played_since_last_interrupt_sized;
+  return 0;
+}
+
 int delay(long *the_delay) {
   // snd_pcm_sframes_t is a signed long -- hence the return of a "long"
   int reply = 0;
@@ -874,12 +954,14 @@ int delay(long *the_delay) {
   if (alsa_handle == NULL) {
     return -ENODEV;
   } else {
-    pthread_cleanup_debug_mutex_lock(&alsa_mutex, 10000, 0);
+    int oldState;
+    pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
+    pthread_cleanup_debug_mutex_lock(&alsa_mutex, 10000, 1);
     int derr;
     snd_pcm_state_t dac_state = snd_pcm_state(alsa_handle);
     if (dac_state == SND_PCM_STATE_RUNNING) {
       *the_delay = 0; // just to see what happens
-      reply = snd_pcm_delay(alsa_handle, the_delay);
+      reply = my_snd_pcm_delay(alsa_handle, the_delay);
       if (reply != 0) {
         debug(1, "Error %d in delay(): \"%s\". Delay reported is %d frames.", reply,
               snd_strerror(reply), *the_delay);
@@ -926,6 +1008,7 @@ int delay(long *the_delay) {
     // here, occasionally pretend there's a problem with pcm_get_delay()
     // if ((random() % 100000) < 3) // keep it pretty rare
     //	reply = -EIO; // pretend something bad has happened
+    pthread_setcancelstate(oldState, NULL);
     return reply;
   }
 }
@@ -945,10 +1028,13 @@ int get_rate_information(uint64_t *elapsed_time, uint64_t *frames_played) {
 
 static int play(void *buf, int samples) {
   // debug(3,"audio_alsa play called.");
+  int oldState;
+  pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
   int ret = 0;
   if (alsa_handle == NULL) {
+
     pthread_cleanup_debug_mutex_lock(&alsa_mutex, 10000, 1);
-    ret = open_alsa_device();
+    ret = actual_open_alsa_device();
     if (ret == 0) {
       if (audio_alsa.volume)
         do_volume(set_volume);
@@ -1003,7 +1089,7 @@ static int play(void *buf, int samples) {
         frame_index++;
         if ((frame_index == start_measurement_from_this_frame) || (frame_index % 32 == 0)) {
           long fl = 0;
-          err2 = snd_pcm_delay(alsa_handle, &fl);
+          err2 = my_snd_pcm_delay(alsa_handle, &fl);
           if (err2 != 0) {
             debug(1, "Error %d in delay in play(): \"%s\". Delay reported is %d frames.", err2,
                   snd_strerror(err2), fl);
@@ -1048,13 +1134,14 @@ static int play(void *buf, int samples) {
     debug_mutex_unlock(&alsa_mutex, 0);
     pthread_cleanup_pop(0); // release the mutex
   }
+  pthread_setcancelstate(oldState, NULL);
   return ret;
 }
 
 static void flush(void) {
   // debug(2,"audio_alsa flush called.");
   int oldState;
-  pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState);
+  pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
   pthread_cleanup_debug_mutex_lock(&alsa_mutex, 10000, 1);
   int derr;
   do_mute(1);
@@ -1095,6 +1182,8 @@ static void parameters(audio_parameters *info) {
 }
 
 void do_volume(double vol) { // caller is assumed to have the alsa_mutex when using this function
+  int oldState;
+  pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
   debug(3, "Setting volume db to %f.", vol);
   set_volume = vol;
   if (volume_set_request && (open_mixer() == 1)) {
@@ -1126,6 +1215,7 @@ void do_volume(double vol) { // caller is assumed to have the alsa_mutex when us
     volume_set_request = 0; // any external request that has been made is now satisfied
     close_mixer();
   }
+  pthread_setcancelstate(oldState, NULL);
 }
 
 void volume(double vol) {
@@ -1166,6 +1256,9 @@ static void mute(int mute_state_requested) {
 
 void do_mute(int mute_state_requested) {
 
+  int oldState;
+  pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState); // make this un-cancellable
+
   // if a mute is requested now, then
   // 	if an external mute request is in place, leave everything muted
   //  otherwise, if an external mute request is pending, action it
@@ -1206,4 +1299,5 @@ void do_mute(int mute_state_requested) {
     }
   }
   mute_request_pending = 0;
+  pthread_setcancelstate(oldState, NULL);
 }

common.c

@@ -739,6 +739,38 @@ void command_start(void) {
     }
   }
 }
+void command_execute(const char *command) {
+  // this has a cancellation point if waiting is enabled
+  if (command) {
+    /*Spawn a child to run the program.*/
+    pid_t pid = fork();
+    if (pid == 0) { /* child process */
+      int argC;
+      char **argV;
+      if (poptParseArgvString(command, &argC, (const char ***)&argV) !=
+          0) // note that argV should be free()'d after use, but we expect this fork to exit
+             // eventually.
+        debug(1, "Can't decipher command arguments in \"%s\".", command);
+      else {
+        // debug(1,"Executing command %s",command);
+        execv(argV[0], argV);
+        warn("Execution of command \"%s\" failed to start", command);
+        debug(1, "Error executing command \"%s\".", command);
+        exit(127); /* only if execv fails */
+      }
+    } else {
+      if (config.cmd_blocking) { /* pid!=0 means parent process and if blocking is true, wait for
+                                    process to finish */
+        pid_t rc = waitpid(pid, 0, 0); /* wait for child to exit */
+        if (rc != pid) {
+          warn("Execution of command \"%s\" returned an error.", command);
+          debug(1, "Command \"%s\" finished with error %d", command, errno);
+        }
+      }
+      // debug(1,"Continue after on-unfixable command");
+    }
+  }
+}
 
 void command_stop(void) {
   // this has a cancellation point if waiting is enabled

common.h

@@ -148,7 +148,7 @@ typedef struct {
   int debugger_show_relative_time; // in the debug message, display the time since the last one
   int statistics_requested, use_negotiated_latencies;
   enum playback_mode_type playback_mode;
-  char *cmd_start, *cmd_stop, *cmd_set_volume;
+  char *cmd_start, *cmd_stop, *cmd_set_volume, *cmd_unfixable;
   int cmd_blocking, cmd_start_returns_output;
   double tolerance; // allow this much drift before attempting to correct it
   enum stuffing_type packet_stuffing;
@@ -296,6 +296,7 @@ int config_set_lookup_bool(config_t *cfg, char *where, int *dst);
 
 void command_start(void);
 void command_stop(void);
+void command_execute(const char *command);
 void command_set_volume(double volume);
 
 int mkpath(const char *path, mode_t mode);

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.3d32], [mikebrady@eircom.net])
+AC_INIT([shairport-sync], [3.3d34], [mikebrady@eircom.net])
 AM_INIT_AUTOMAKE
 AC_CONFIG_SRCDIR([shairport.c])
 AC_CONFIG_HEADERS([config.h])

player.h

@@ -82,13 +82,14 @@ typedef struct {
   char *auth_nonce; // the session nonce, if needed
   stream_cfg stream;
   SOCKADDR remote, local;
-  int stop;
-  int running;
+  volatile int stop;
+  volatile int running;
+  volatile uint64_t watchdog_bark_time;
+  volatile int watchdog_barks; // number of times the watchdog has timed out and done something
+
   time_t playstart;
   pthread_t thread, timer_requester, rtp_audio_thread, rtp_control_thread, rtp_timing_thread,
       player_watchdog_thread;
-  int64_t watchdog_bark_time;
-  // pthread_t *ptp;
 
   // buffers to delete on exit
   signed short *tbuf;

rtp.c

@@ -482,7 +482,13 @@ void *rtp_control_receiver(void *arg) {
   pthread_exit(NULL);
 }
 
+void rtp_timing_sender_cleanup_handler(void *arg) {
+  rtsp_conn_info *conn = (rtsp_conn_info *)arg;
+  debug(3, "Connection %d: Timing Sender Cleanup.", conn->connection_number);
+}
+
 void *rtp_timing_sender(void *arg) {
+  pthread_cleanup_push(rtp_timing_sender_cleanup_handler, arg);
   rtsp_conn_info *conn = (rtsp_conn_info *)arg;
   struct timing_request {
     char leader;
@@ -542,6 +548,7 @@ void *rtp_timing_sender(void *arg) {
       usleep(3000000);
   }
   debug(3, "rtp_timing_sender thread interrupted. This should never happen.");
+  pthread_cleanup_pop(0); // don't execute anything here.
   pthread_exit(NULL);
 }
 

rtsp.c

@@ -283,11 +283,25 @@ void *player_watchdog_thread_code(void *arg) {
         uint64_t ct = config.timeout; // go from int to 64-bit int
 
         if (time_since_last_bark >= ct) {
-          debug(1, "Connection %d: As Yeats almost said, \"Too long a silence / can make a stone "
-                   "of the heart\".",
-                conn->connection_number);
-          conn->stop = 1;
-          pthread_cancel(conn->thread);
+          conn->watchdog_barks++;
+          if (conn->watchdog_barks == 1) {
+            debug(1, "Connection %d: As Yeats almost said, \"Too long a silence / can make a stone "
+                     "of the heart\".",
+                  conn->connection_number);
+            conn->stop = 1;
+            pthread_cancel(conn->thread);
+          } else if (conn->watchdog_barks == 3) {
+            if (config.cmd_unfixable) {
+              warn("Connection %d: An unfixable error has been detected. Executing the "
+                   "\"run_this_if_an_unfixable_error_is_detected\" command.",
+                   conn->connection_number);
+              command_execute(config.cmd_unfixable);
+            } else {
+              warn("Connection %d: An unfixable error has been detected. \"No "
+                   "run_this_if_an_unfixable_error_is_detected\" command provided -- nothing done.",
+                   conn->connection_number);
+            }
+          }
         }
       }
     }
@@ -2144,7 +2158,8 @@ void msg_cleanup_function(void *arg) {
 static void *rtsp_conversation_thread_func(void *pconn) {
   rtsp_conn_info *conn = pconn;
 
-  // create the watchdog mutex and start the watchdog thread;
+  // create the watchdog mutex, initialise the watchdog time and start the watchdog thread;
+  conn->watchdog_bark_time = get_absolute_time_in_fp();
   pthread_mutex_init(&conn->watchdog_mutex, NULL);
   pthread_create(&conn->player_watchdog_thread, NULL, &player_watchdog_thread_code, (void *)conn);
 
@@ -2394,6 +2409,11 @@ void rtsp_listen_loop(void) {
     if (setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, (const char *)&tv, sizeof tv) == -1)
       debug(1, "Error %d setting send timeout for rtsp writeback.", errno);
 
+    tv.tv_sec = 30; // 30 seconds read timeout
+    tv.tv_usec = 0;
+    if (setsockopt(fd, SOL_SOCKET, SO_RCVTIMEO, (const char *)&tv, sizeof tv) == -1)
+      debug(1, "Error %d setting send timeout for rtsp writeback.", errno);
+
 #ifdef IPV6_V6ONLY
     // some systems don't support v4 access on v6 sockets, but some do.
     // since we need to account for two sockets we might as well

scripts/shairport-sync.conf

@@ -53,6 +53,7 @@ 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
 //	run_this_after_play_ends = "/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
+//	run_this_if_an_unfixable_error_is_detected = "/full/path/to/application and args"; // if a problem occurs that can't be cleared. It might restart the whole device.
 //	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.

shairport.c

@@ -721,6 +721,11 @@ int parse_options(int argc, char **argv) {
         config.cmd_stop = (char *)str;
       }
 
+      if (config_lookup_string(config.cfg,
+                               "sessioncontrol.run_this_if_an_unfixable_error_is_detected", &str)) {
+        config.cmd_unfixable = (char *)str;
+      }
+
       if (config_lookup_string(config.cfg, "sessioncontrol.wait_for_completion", &str)) {
         if (strcasecmp(str, "no") == 0)
           config.cmd_blocking = 0;