Partially clean up some mutex diagnostic stuff.

diff --git a/common.c b/common.c
index 4ac0e2fe47b510089a9bb2415e05b119e0a8d866..0a582cdaa35d6988d5aa6562e6c3cc3874c39342 100644 (file)
--- a/common.c
+++ b/common.c
@@ -1520,8 +1520,7 @@ void sps_nanosleep(const time_t sec, const long nanosec) {
 // Also note that timing must be relative to CLOCK_REALTIME
 
 #ifdef COMPILE_FOR_LINUX_AND_FREEBSD_AND_CYGWIN_AND_OPENBSD
-int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
-                                const char *debugmessage, int debuglevel) {
+int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time) {
 
   int oldState;
   pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState);
@@ -1534,30 +1533,15 @@ int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
   uint64_t wait_until_nsec = wait_until_time % 1000000000;
   timeoutTime.tv_sec = wait_until_sec;
   timeoutTime.tv_nsec = wait_until_nsec;
-
   int r = pthread_mutex_timedlock(mutex, &timeoutTime);
-  uint64_t et = get_realtime_in_ns() - start_time;
-
-  if ((debuglevel != 0) && (r != 0) && (debugmessage != NULL)) {
-    char errstr[1000];
-    if (r == ETIMEDOUT)
-      debug(debuglevel,
-            "Timed out waiting for a mutex, having waited %f seconds with a maximum "
-            "waiting time of %f seconds. \"%s\".",
-            (1.0 * et) / 1000000000, dally_time * 0.000001, debugmessage);
-    else
-      debug(debuglevel, "error %d: \"%s\" waiting for a mutex: \"%s\".", r,
-            strerror_r(r, errstr, sizeof(errstr)), debugmessage);
-  }
   pthread_setcancelstate(oldState, NULL);
   return r;
 }
 #endif
 #ifdef COMPILE_FOR_OSX
-int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
-                                const char *debugmessage, int debuglevel) {
+int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time) {
 
-  // this is not pthread_cancellation safe because is contains a cancellation point
+  // this would not be not pthread_cancellation safe because is contains a cancellation point
   int oldState;
   pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldState);
   int time_to_wait = dally_time;
@@ -1570,17 +1554,6 @@ int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
     time_to_wait -= st;
     r = pthread_mutex_trylock(mutex);
   }
-  if ((debuglevel != 0) && (r != 0) && (debugmessage != NULL)) {
-    char errstr[1000];
-    if (r == EBUSY) {
-      debug(debuglevel, "waiting for a mutex, maximum expected time of %f seconds exceeded \"%s\".",
-            dally_time * 0.000001, debugmessage);
-      r = ETIMEDOUT; // for compatibility
-    } else {
-      debug(debuglevel, "error %d: \"%s\" waiting for a mutex: \"%s\".", r,
-            strerror_r(r, errstr, sizeof(errstr)), debugmessage);
-    }
-  }
   pthread_setcancelstate(oldState, NULL);
   return r;
 }
@@ -1597,14 +1570,14 @@ int _debug_mutex_lock(pthread_mutex_t *mutex, useconds_t dally_time, const char
   memset(dstring, 0, sizeof(dstring));
   snprintf(dstring, sizeof(dstring), "%s:%d", filename, line);
   if (debuglevel != 0)
-    debug(3, "mutex_lock \"%s\" at \"%s\".", mutexname, dstring); // only if you really ask for it!
-  int result = sps_pthread_mutex_timedlock(mutex, dally_time, dstring, debuglevel);
+    _debug(filename, line, 3, "mutex_lock \"%s\" at \"%s\".", mutexname, dstring); // only if you really ask for it!
+  int result = sps_pthread_mutex_timedlock(mutex, dally_time);
   if (result == ETIMEDOUT) {
     result = pthread_mutex_lock(mutex);
     uint64_t time_delay = get_absolute_time_in_ns() - time_at_start;
-    debug(debuglevel,
-          "Mutex_lock \"%s\" at \"%s\" expected max wait: %0.9f, actual wait: %0.9f sec.",
-          mutexname, dstring, (1.0 * dally_time) / 1000000, 0.000000001 * time_delay);
+    _debug(filename, line, debuglevel,
+          "mutex_lock \"%s\" expected max wait: %" PRId64 " ns, actual wait: %u microseconds.",
+          mutexname, (1.0 * dally_time) / 1000000, 0.000000001 * time_delay);
   }
   pthread_setcancelstate(oldState, NULL);
   return result;

diff --git a/common.h b/common.h
index f81540b7994e3a1438f04507d1e9ed73fa6160f5..321eeea2522e67cab99f81f015dd1b5d230b64bd 100644 (file)
--- a/common.h
+++ b/common.h
@@ -423,8 +423,8 @@ extern pthread_mutex_t the_conn_lock;
   pthread_mutex_unlock(&the_conn_lock);
 
 // wait for the specified time in microseconds -- it checks every 20 milliseconds
-int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
-                                const char *debugmessage, int debuglevel);
+// int sps_pthread_mutex_timedlock(pthread_mutex_t *mutex, useconds_t dally_time,
+//                                 const char *debugmessage, int debuglevel);
 // wait for the specified time, checking every 20 milliseconds, and block if it can't acquire the
 // lock
 int _debug_mutex_lock(pthread_mutex_t *mutex, useconds_t dally_time, const char *mutexName,

diff --git a/dacp.c b/dacp.c
index 7184ed7344b5418968f624df97d0ba487f259639..8bacf3d7368f771bd531687ce817e3787828ad7e 100644 (file)
--- a/dacp.c
+++ b/dacp.c
@@ -206,7 +206,8 @@ int dacp_send_command(const char *command, char **body, ssize_t *bodysize) {
       pthread_cleanup_push(addrinfo_cleanup, (void *)&res);
       // only do this one at a time -- not sure it is necessary, but better safe than sorry
 
-      int mutex_reply = sps_pthread_mutex_timedlock(&dacp_conversation_lock, 2000000, command, 1);
+      // int mutex_reply = sps_pthread_mutex_timedlock(&dacp_conversation_lock, 2000000, command, 1);
+      int mutex_reply = debug_mutex_lock(&dacp_conversation_lock, 2000000, 1);
       // int mutex_reply = pthread_mutex_lock(&dacp_conversation_lock);
       if (mutex_reply == 0) {
         pthread_cleanup_push(mutex_lock_cleanup, (void *)&dacp_conversation_lock);
@@ -488,11 +489,6 @@ void dacp_monitor_port_update_callback(char *dacp_id, uint16_t port) {
   debug_mutex_unlock(&dacp_server_information_lock, 3);
 }
 
-void dacp_monitor_thread_code_cleanup(__attribute__((unused)) void *arg) {
-  // debug(1, "dacp_monitor_thread_code_cleanup called.");
-  pthread_mutex_unlock(&dacp_server_information_lock);
-}
-
 void *dacp_monitor_thread_code(__attribute__((unused)) void *na) {
   int scan_index = 0;
   int always_use_revision_number_1 = 0;
@@ -504,12 +500,8 @@ void *dacp_monitor_thread_code(__attribute__((unused)) void *na) {
   int idle_scan_count = 0;
   while (1) {
     int result = 0;
-    sps_pthread_mutex_timedlock(
-        &dacp_server_information_lock, 500000,
-        "dacp_monitor_thread_code couldn't get DACP server information lock in 0.5 second!.", 2);
     int32_t the_volume;
-
-    pthread_cleanup_push(dacp_monitor_thread_code_cleanup, NULL);
+    pthread_cleanup_debug_mutex_lock(&dacp_server_information_lock, 500000, 2);
     if (dacp_server.scan_enable == 0) {
       metadata_hub_modify_prolog();
       int ch = (metadata_store.dacp_server_active != 0) ||