From 0964a94ad528ac2d84cecb99ebdf74d76677e559 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20K=C4=99pie=C5=84?= Date: Thu, 9 Dec 2021 12:24:12 +0100 Subject: [PATCH] Remove mutex profiling code Mutex profiling code (used when the ISC_MUTEX_PROFILE preprocessor macro is set to 1) has been broken for the past 3 years (since commit 0bed9bfc28a204cde57c6f68170ecc89ebfa6dc8) and nobody complained, which is a strong indication that this code is not being used these days any more. External tools for both measuring performance and detecting locking issues are already wired into various GitLab CI checks. Drop all code depending on the ISC_MUTEX_PROFILE preprocessor macro being set. --- bin/named/main.c | 2 - lib/isc/condition.c | 4 - lib/isc/include/isc/condition.h | 6 - lib/isc/include/isc/mutex.h | 61 ---------- lib/isc/mutex.c | 200 +------------------------------- 5 files changed, 2 insertions(+), 271 deletions(-) diff --git a/bin/named/main.c b/bin/named/main.c index f2f200a3f4..65836b3c25 100644 --- a/bin/named/main.c +++ b/bin/named/main.c @@ -1493,7 +1493,6 @@ main(int argc, char *argv[]) { if (want_stats) { isc_mem_stats(named_g_mctx, stdout); - isc_mutex_stats(stdout); } if (named_g_memstatistics && memstats != NULL) { @@ -1501,7 +1500,6 @@ main(int argc, char *argv[]) { result = isc_stdio_open(memstats, "w", &fp); if (result == ISC_R_SUCCESS) { isc_mem_stats(named_g_mctx, fp); - isc_mutex_stats(fp); (void)isc_stdio_close(fp); } } diff --git a/lib/isc/condition.c b/lib/isc/condition.c index ac9fcea809..6409fcee3a 100644 --- a/lib/isc/condition.c +++ b/lib/isc/condition.c @@ -50,11 +50,7 @@ isc_condition_waituntil(isc_condition_t *c, isc_mutex_t *m, isc_time_t *t) { ts.tv_nsec = (long)isc_time_nanoseconds(t); do { -#if ISC_MUTEX_PROFILE - presult = pthread_cond_timedwait(c, &m->mutex, &ts); -#else /* if ISC_MUTEX_PROFILE */ presult = pthread_cond_timedwait(c, m, &ts); -#endif /* if ISC_MUTEX_PROFILE */ if (presult == 0) { return (ISC_R_SUCCESS); } diff --git a/lib/isc/include/isc/condition.h b/lib/isc/include/isc/condition.h index aed1db088c..a29f0967b7 100644 --- a/lib/isc/include/isc/condition.h +++ b/lib/isc/include/isc/condition.h @@ -35,15 +35,9 @@ typedef pthread_cond_t isc_condition_t; isc_condition_strbuf); \ } -#if ISC_MUTEX_PROFILE -#define isc_condition_wait(cp, mp) \ - ((pthread_cond_wait((cp), &((mp)->mutex)) == 0) ? ISC_R_SUCCESS \ - : ISC_R_UNEXPECTED) -#else /* if ISC_MUTEX_PROFILE */ #define isc_condition_wait(cp, mp) \ ((pthread_cond_wait((cp), (mp)) == 0) ? ISC_R_SUCCESS \ : ISC_R_UNEXPECTED) -#endif /* if ISC_MUTEX_PROFILE */ #define isc_condition_signal(cp) \ ((pthread_cond_signal((cp)) == 0) ? ISC_R_SUCCESS : ISC_R_UNEXPECTED) diff --git a/lib/isc/include/isc/mutex.h b/lib/isc/include/isc/mutex.h index 295bef2123..d930a180e3 100644 --- a/lib/isc/include/isc/mutex.h +++ b/lib/isc/include/isc/mutex.h @@ -37,30 +37,8 @@ extern pthread_mutexattr_t isc__mutex_attrs; /* XXX We could do fancier error handling... */ -/*! - * Define ISC_MUTEX_PROFILE to turn on profiling of mutexes by line. When - * enabled, isc_mutex_stats() can be used to print a table showing the - * number of times each type of mutex was locked and the amount of time - * waiting to obtain the lock. - */ -#ifndef ISC_MUTEX_PROFILE -#define ISC_MUTEX_PROFILE 0 -#endif /* ifndef ISC_MUTEX_PROFILE */ - -#if ISC_MUTEX_PROFILE -typedef struct isc_mutexstats isc_mutexstats_t; - -typedef struct { - pthread_mutex_t mutex; /*%< The actual mutex. */ - isc_mutexstats_t *stats; /*%< Mutex statistics. */ -} isc_mutex_t; -#else /* if ISC_MUTEX_PROFILE */ typedef pthread_mutex_t isc_mutex_t; -#endif /* if ISC_MUTEX_PROFILE */ -#if ISC_MUTEX_PROFILE -#define isc_mutex_init(mp) isc_mutex_init_profile((mp), __FILE__, __LINE__) -#else /* if ISC_MUTEX_PROFILE */ #if ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK) #define isc_mutex_init(mp) isc_mutex_init_errcheck((mp)) #else /* if ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK) */ @@ -68,56 +46,17 @@ typedef pthread_mutex_t isc_mutex_t; void isc__mutex_init(isc_mutex_t *mp, const char *file, unsigned int line); #endif /* if ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK) */ -#endif /* if ISC_MUTEX_PROFILE */ -#if ISC_MUTEX_PROFILE -#define isc_mutex_lock(mp) isc_mutex_lock_profile((mp), __FILE__, __LINE__) -#else /* if ISC_MUTEX_PROFILE */ #define isc_mutex_lock(mp) \ ((pthread_mutex_lock((mp)) == 0) ? ISC_R_SUCCESS : ISC_R_UNEXPECTED) -#endif /* if ISC_MUTEX_PROFILE */ -#if ISC_MUTEX_PROFILE -#define isc_mutex_unlock(mp) isc_mutex_unlock_profile((mp), __FILE__, __LINE__) -#else /* if ISC_MUTEX_PROFILE */ #define isc_mutex_unlock(mp) \ ((pthread_mutex_unlock((mp)) == 0) ? ISC_R_SUCCESS : ISC_R_UNEXPECTED) -#endif /* if ISC_MUTEX_PROFILE */ -#if ISC_MUTEX_PROFILE -#define isc_mutex_trylock(mp) \ - ((pthread_mutex_trylock((&(mp)->mutex)) == 0) ? ISC_R_SUCCESS \ - : ISC_R_LOCKBUSY) -#else /* if ISC_MUTEX_PROFILE */ #define isc_mutex_trylock(mp) \ ((pthread_mutex_trylock((mp)) == 0) ? ISC_R_SUCCESS : ISC_R_LOCKBUSY) -#endif /* if ISC_MUTEX_PROFILE */ -#if ISC_MUTEX_PROFILE -#define isc_mutex_destroy(mp) \ - RUNTIME_CHECK(pthread_mutex_destroy((&(mp)->mutex)) == 0) -#else /* if ISC_MUTEX_PROFILE */ #define isc_mutex_destroy(mp) RUNTIME_CHECK(pthread_mutex_destroy((mp)) == 0) -#endif /* if ISC_MUTEX_PROFILE */ - -#if ISC_MUTEX_PROFILE -#define isc_mutex_stats(fp) isc_mutex_statsprofile(fp); -#else /* if ISC_MUTEX_PROFILE */ -#define isc_mutex_stats(fp) -#endif /* if ISC_MUTEX_PROFILE */ - -#if ISC_MUTEX_PROFILE - -void -isc_mutex_init_profile(isc_mutex_t *mp, const char *_file, int _line); -isc_result_t -isc_mutex_lock_profile(isc_mutex_t *mp, const char *_file, int _line); -isc_result_t -isc_mutex_unlock_profile(isc_mutex_t *mp, const char *_file, int _line); - -void -isc_mutex_statsprofile(FILE *fp); -#endif /* ISC_MUTEX_PROFILE */ void isc_mutex_init_errcheck(isc_mutex_t *mp); diff --git a/lib/isc/mutex.c b/lib/isc/mutex.c index 1b5a839888..562dedcffe 100644 --- a/lib/isc/mutex.c +++ b/lib/isc/mutex.c @@ -24,200 +24,6 @@ #include #include -#if ISC_MUTEX_PROFILE - -/*@{*/ -/*% Operations on timevals; adapted from FreeBSD's sys/time.h */ -#define timevalclear(tvp) ((tvp)->tv_sec = (tvp)->tv_usec = 0) -#define timevaladd(vvp, uvp) \ - do { \ - (vvp)->tv_sec += (uvp)->tv_sec; \ - (vvp)->tv_usec += (uvp)->tv_usec; \ - if ((vvp)->tv_usec >= 1000000) { \ - (vvp)->tv_sec++; \ - (vvp)->tv_usec -= 1000000; \ - } \ - } while (0) -#define timevalsub(vvp, uvp) \ - do { \ - (vvp)->tv_sec -= (uvp)->tv_sec; \ - (vvp)->tv_usec -= (uvp)->tv_usec; \ - if ((vvp)->tv_usec < 0) { \ - (vvp)->tv_sec--; \ - (vvp)->tv_usec += 1000000; \ - } \ - } while (0) - -/*@}*/ - -#define ISC_MUTEX_MAX_LOCKERS 32 - -typedef struct { - const char *file; - int line; - unsigned count; - struct timeval locked_total; - struct timeval wait_total; -} isc_mutexlocker_t; - -struct isc_mutexstats { - const char *file; /*%< File mutex was created in. */ - int line; /*%< Line mutex was created on. */ - unsigned count; - struct timeval lock_t; - struct timeval locked_total; - struct timeval wait_total; - isc_mutexlocker_t *cur_locker; - isc_mutexlocker_t lockers[ISC_MUTEX_MAX_LOCKERS]; -}; - -#ifndef ISC_MUTEX_PROFTABLESIZE -#define ISC_MUTEX_PROFTABLESIZE (1024 * 1024) -#endif /* ifndef ISC_MUTEX_PROFTABLESIZE */ -static isc_mutexstats_t stats[ISC_MUTEX_PROFTABLESIZE]; -static int stats_next = 0; -static bool stats_init = false; -static pthread_mutex_t statslock = PTHREAD_MUTEX_INITIALIZER; - -void -isc_mutex_init_profile(isc_mutex_t *mp, const char *file, int line) { - int i, err; - - err = pthread_mutex_init(&mp->mutex, NULL); - if (err != 0) { - strerror_r(err, strbuf, sizeof(strbuf)); - isc_error_fatal(file, line, "pthread_mutex_init failed: %s", - strbuf); - } - - RUNTIME_CHECK(pthread_mutex_lock(&statslock) == 0); - - if (!stats_init) { - stats_init = true; - } - - /* - * If all statistics entries have been used, give up and trigger an - * assertion failure. There would be no other way to deal with this - * because we'd like to keep record of all locks for the purpose of - * debugging and the number of necessary locks is unpredictable. - * If this failure is triggered while debugging, named should be - * rebuilt with an increased ISC_MUTEX_PROFTABLESIZE. - */ - RUNTIME_CHECK(stats_next < ISC_MUTEX_PROFTABLESIZE); - mp->stats = &stats[stats_next++]; - - RUNTIME_CHECK(pthread_mutex_unlock(&statslock) == 0); - - mp->stats->file = file; - mp->stats->line = line; - mp->stats->count = 0; - timevalclear(&mp->stats->locked_total); - timevalclear(&mp->stats->wait_total); - for (i = 0; i < ISC_MUTEX_MAX_LOCKERS; i++) { - mp->stats->lockers[i].file = NULL; - mp->stats->lockers[i].line = 0; - mp->stats->lockers[i].count = 0; - timevalclear(&mp->stats->lockers[i].locked_total); - timevalclear(&mp->stats->lockers[i].wait_total); - } -} - -isc_result_t -isc_mutex_lock_profile(isc_mutex_t *mp, const char *file, int line) { - struct timeval prelock_t; - struct timeval postlock_t; - isc_mutexlocker_t *locker = NULL; - int i; - - gettimeofday(&prelock_t, NULL); - - if (pthread_mutex_lock(&mp->mutex) != 0) { - return (ISC_R_UNEXPECTED); - } - - gettimeofday(&postlock_t, NULL); - mp->stats->lock_t = postlock_t; - - timevalsub(&postlock_t, &prelock_t); - - mp->stats->count++; - timevaladd(&mp->stats->wait_total, &postlock_t); - - for (i = 0; i < ISC_MUTEX_MAX_LOCKERS; i++) { - if (mp->stats->lockers[i].file == NULL) { - locker = &mp->stats->lockers[i]; - locker->file = file; - locker->line = line; - break; - } else if (mp->stats->lockers[i].file == file && - mp->stats->lockers[i].line == line) - { - locker = &mp->stats->lockers[i]; - break; - } - } - - if (locker != NULL) { - locker->count++; - timevaladd(&locker->wait_total, &postlock_t); - } - - mp->stats->cur_locker = locker; - - return (ISC_R_SUCCESS); -} - -isc_result_t -isc_mutex_unlock_profile(isc_mutex_t *mp, const char *file, int line) { - struct timeval unlock_t; - - UNUSED(file); - UNUSED(line); - - if (mp->stats->cur_locker != NULL) { - gettimeofday(&unlock_t, NULL); - timevalsub(&unlock_t, &mp->stats->lock_t); - timevaladd(&mp->stats->locked_total, &unlock_t); - timevaladd(&mp->stats->cur_locker->locked_total, &unlock_t); - mp->stats->cur_locker = NULL; - } - - return ((pthread_mutex_unlock((&mp->mutex)) == 0) ? ISC_R_SUCCESS - : ISC_R_UNEXPECTED); -} - -void -isc_mutex_statsprofile(FILE *fp) { - isc_mutexlocker_t *locker; - int i, j; - - fprintf(fp, "Mutex stats (in us)\n"); - for (i = 0; i < stats_next; i++) { - fprintf(fp, "%-12s %4d: %10u %lu.%06lu %lu.%06lu %5d\n", - stats[i].file, stats[i].line, stats[i].count, - stats[i].locked_total.tv_sec, - stats[i].locked_total.tv_usec, - stats[i].wait_total.tv_sec, stats[i].wait_total.tv_usec, - i); - for (j = 0; j < ISC_MUTEX_MAX_LOCKERS; j++) { - locker = &stats[i].lockers[j]; - if (locker->file == NULL) { - continue; - } - fprintf(fp, - " %-11s %4d: %10u %lu.%06lu %lu.%06lu %5d\n", - locker->file, locker->line, locker->count, - locker->locked_total.tv_sec, - locker->locked_total.tv_usec, - locker->wait_total.tv_sec, - locker->wait_total.tv_usec, i); - } - } -} - -#endif /* ISC_MUTEX_PROFILE */ - #if ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK) static bool errcheck_initialized = false; @@ -257,8 +63,7 @@ pthread_mutexattr_t isc__mutex_attrs = { #endif /* if ISC_MUTEX_DEBUG && defined(__NetBSD__) && \ * defined(PTHREAD_MUTEX_ERRORCHECK) */ -#if !(ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK)) && \ - !ISC_MUTEX_PROFILE +#if !(ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK)) #ifdef HAVE_PTHREAD_MUTEX_ADAPTIVE_NP static bool attr_initialized = false; @@ -296,5 +101,4 @@ isc__mutex_init(isc_mutex_t *mp, const char *file, unsigned int line) { strbuf); } } -#endif /* if !(ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK)) && \ - * !ISC_MUTEX_PROFILE */ +#endif /* if !(ISC_MUTEX_DEBUG && defined(PTHREAD_MUTEX_ERRORCHECK)) */