From: Mike Brady <4265913+mikebrady@users.noreply.github.com> Date: Wed, 18 May 2022 18:37:18 +0000 (+0100) Subject: Partially clean up some mutex diagnostic stuff. X-Git-Tag: 4.1-rc1~24^2~214 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=2dc6af2daffcdb30468f567fcce265bb3881031d;p=thirdparty%2Fshairport-sync.git Partially clean up some mutex diagnostic stuff. --- diff --git a/common.c b/common.c index 4ac0e2fe..0a582cda 100644 --- 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 f81540b7..321eeea2 100644 --- 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 7184ed73..8bacf3d7 100644 --- 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) ||