Partially clean up some mutex diagnostic stuff.

This commit is contained in:
Mike Brady
2022-05-18 19:37:18 +01:00
parent 016354a970
commit 2dc6af2daf
3 changed files with 13 additions and 48 deletions
+8 -35
View File
@@ -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;
+2 -2
View File
@@ -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,
+3 -11
View File
@@ -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) ||