summaryrefslogtreecommitdiffstats
path: root/src
diff options
context:
space:
mode:
Diffstat (limited to 'src')
-rw-r--r--src/include/ChangeLog24
-rw-r--r--src/include/k5-thread.h50
-rw-r--r--src/util/support/ChangeLog12
-rw-r--r--src/util/support/Makefile.in1
-rw-r--r--src/util/support/libkrb5support.exports3
-rw-r--r--src/util/support/threads.c109
6 files changed, 189 insertions, 10 deletions
diff --git a/src/include/ChangeLog b/src/include/ChangeLog
index 4646329bd2..b4d1f4bbff 100644
--- a/src/include/ChangeLog
+++ b/src/include/ChangeLog
@@ -1,3 +1,27 @@
+2004-12-06 Ken Raeburn <raeburn@mit.edu>
+
+ * k5-thread.h [DEBUG_THREADS_STATS]: Include string.h and
+ inttypes.h.
+ (get_current_time) [DEBUG_THREADS_STATS]: Define as inline.
+ (k5_mutex_init_stats) [DEBUG_THREADS_STATS]: Save away current
+ time as creation time.
+ (k5_mutex_stats_tmp): New typedef, k5_debug_time_t if recording
+ stats, dummy int otherwise.
+ (k5_mutex_stats_start): New macro, get current time if recording,
+ zero otherwise.
+ (krb5int_mutex_lock_update_stats,
+ krb5int_mutex_unlock_update_stats, krb5int_mutex_report_stats)
+ [DEBUG_THREADS_STATS]: Declare.
+ (krb5int_mutex_report_stats) [! DEBUG_THREADS_STATS]: New macro,
+ does nothing.
+ (k5_mutex_lock_update_stats, k5_mutex_unlock_update_stats): New
+ macros, map to krb5int_ functions if recording, dummy statements
+ otherwise.
+ (k5_mutex_destroy): Call krb5int_mutex_report_stats.
+ (k5_mutex_lock, k5_mutex_lock_1): Call k5_mutex_stats_start and
+ k5_mutex_lock_update_stats.
+ (k5_mutex_unlock_1): Call k5_mutex_unlock_update_stats.
+
2004-11-19 Ken Raeburn <raeburn@mit.edu>
* win-mac.h (HAVE_GETADDRINFO, HAVE_GETNAMEINFO): Define.
diff --git a/src/include/k5-thread.h b/src/include/k5-thread.h
index 5fecf08275..88b6bf3b9a 100644
--- a/src/include/k5-thread.h
+++ b/src/include/k5-thread.h
@@ -193,14 +193,23 @@ typedef char k5_debug_loc;
#ifdef HAVE_STDINT_H
# include <stdint.h>
#endif
+/* for memset */
+#include <string.h>
+/* for uint64_t */
#include <inttypes.h>
-typedef uint64_t k5_debug_timediff_t;
+typedef uint64_t k5_debug_timediff_t; /* or long double */
typedef struct timeval k5_debug_time_t;
static inline k5_debug_timediff_t
timediff(k5_debug_time_t t2, k5_debug_time_t t1)
{
return (t2.tv_sec - t1.tv_sec) * 1000000 + (t2.tv_usec - t1.tv_usec);
}
+static inline k5_debug_time_t get_current_time(void)
+{
+ struct timeval tv;
+ if (gettimeofday(&tv,0) < 0) { tv.tv_sec = tv.tv_usec = 0; }
+ return tv;
+}
struct k5_timediff_stats {
k5_debug_timediff_t valmin, valmax, valsum, valsqsum;
};
@@ -209,10 +218,20 @@ typedef struct {
k5_debug_time_t time_acquired, time_created;
struct k5_timediff_stats lockwait, lockheld;
} k5_debug_mutex_stats;
-#define k5_mutex_init_stats(S) \
- (memset((S), 0, sizeof(struct k5_debug_mutex_stats)), 0)
+#define k5_mutex_init_stats(S) \
+ (memset((S), 0, sizeof(k5_debug_mutex_stats)), \
+ (S)->time_created = get_current_time(), \
+ 0)
#define k5_mutex_finish_init_stats(S) (0)
#define K5_MUTEX_STATS_INIT { 0, {0}, {0}, {0}, {0} }
+typedef k5_debug_time_t k5_mutex_stats_tmp;
+#define k5_mutex_stats_start() get_current_time()
+extern void krb5int_mutex_lock_update_stats(k5_debug_mutex_stats *m,
+ k5_mutex_stats_tmp startwait);
+extern void krb5int_mutex_unlock_update_stats(k5_debug_mutex_stats *m);
+#define k5_mutex_lock_update_stats krb5int_mutex_lock_update_stats
+#define k5_mutex_unlock_update_stats krb5int_mutex_unlock_update_stats
+extern void krb5int_mutex_report_stats();
#else
@@ -220,6 +239,11 @@ typedef char k5_debug_mutex_stats;
#define k5_mutex_init_stats(S) (*(S) = 's', 0)
#define k5_mutex_finish_init_stats(S) (0)
#define K5_MUTEX_STATS_INIT 's'
+typedef int k5_mutex_stats_tmp;
+#define k5_mutex_stats_start() (0)
+#define k5_mutex_lock_update_stats(M,S) (S)
+#define k5_mutex_unlock_update_stats(M) (*(M) = 's')
+#define krb5int_mutex_report_stats(M) ((M)->stats = 'd')
#endif
@@ -614,25 +638,30 @@ static inline int k5_mutex_finish_init_1(k5_mutex_t *m, k5_debug_loc l)
#define k5_mutex_finish_init(M) k5_mutex_finish_init_1((M), K5_DEBUG_LOC)
#define k5_mutex_destroy(M) \
(k5_os_mutex_assert_unlocked(&(M)->os), \
+ krb5int_mutex_report_stats(M), \
(M)->loc_last = K5_DEBUG_LOC, \
k5_os_mutex_destroy(&(M)->os))
#ifdef __GNUC__
-#define k5_mutex_lock(M) \
- __extension__ ({ \
- int _err = 0; \
- k5_mutex_t *_m = (M); \
- _err = k5_os_mutex_lock(&_m->os); \
- if (_err == 0) _m->loc_last = K5_DEBUG_LOC; \
- _err; \
+#define k5_mutex_lock(M) \
+ __extension__ ({ \
+ int _err = 0; \
+ k5_mutex_stats_tmp _stats = k5_mutex_stats_start(); \
+ k5_mutex_t *_m = (M); \
+ _err = k5_os_mutex_lock(&_m->os); \
+ if (_err == 0) _m->loc_last = K5_DEBUG_LOC; \
+ if (_err == 0) k5_mutex_lock_update_stats(&_m->stats, _stats); \
+ _err; \
})
#else
static inline int k5_mutex_lock_1(k5_mutex_t *m, k5_debug_loc l)
{
int err = 0;
+ k5_mutex_stats_tmp stats = k5_mutex_stats_start();
err = k5_os_mutex_lock(&m->os);
if (err)
return err;
m->loc_last = l;
+ k5_mutex_lock_update_stats(&m->stats, stats);
return err;
}
#define k5_mutex_lock(M) k5_mutex_lock_1(M, K5_DEBUG_LOC)
@@ -640,6 +669,7 @@ static inline int k5_mutex_lock_1(k5_mutex_t *m, k5_debug_loc l)
static inline int k5_mutex_unlock_1(k5_mutex_t *m, k5_debug_loc l)
{
int err = 0;
+ k5_mutex_unlock_update_stats(&m->stats);
err = k5_os_mutex_unlock(&m->os);
if (err)
return err;
diff --git a/src/util/support/ChangeLog b/src/util/support/ChangeLog
index 2c2a3252da..a49aa78cb3 100644
--- a/src/util/support/ChangeLog
+++ b/src/util/support/ChangeLog
@@ -1,3 +1,15 @@
+2004-12-06 Ken Raeburn <raeburn@mit.edu>
+
+ * threads.c [DEBUG_THREADS_STATS]: Include stdio.h.
+ (stats_logfile) [DEBUG_THREADS_STATS]: New variable.
+ (krb5int_thread_support_init) [DEBUG_THREADS_STATS]: Set it to
+ point to a file on /dev/tty or stderr.
+ (krb5int_thread_support_fini) [DEBUG_THREADS_STATS]: Flush it.
+ (k5_mutex_lock_update_stats, krb5int_mutex_unlock_update_stats,
+ get_stddev, krb5int_mutex_report_stats) [DEBUG_THREADS_STATS]: New
+ functions.
+ * libkrb5support.exports: Add krb5int_mutex_*_stats.
+
2004-11-19 Ken Raeburn <raeburn@mit.edu>
* fake-addrinfo.c (HAVE_GETADDRINFO, HAVE_GETNAMEINFO)[_WIN32]:
diff --git a/src/util/support/Makefile.in b/src/util/support/Makefile.in
index e17b46a6e6..61188db4e6 100644
--- a/src/util/support/Makefile.in
+++ b/src/util/support/Makefile.in
@@ -43,6 +43,7 @@ SRCS=\
$(srcdir)/init-addrinfo.c \
$(srcdir)/fake-addrinfo.c
SHLIB_EXPDEPS =
+# Add -lm if dumping thread stats, for sqrt.
SHLIB_EXPLIBS= $(LIBS)
SHLIB_DIRS=
SHLIB_RDIRS=$(KRB5_LIBDIR)
diff --git a/src/util/support/libkrb5support.exports b/src/util/support/libkrb5support.exports
index 5e8208306d..9a415acf7e 100644
--- a/src/util/support/libkrb5support.exports
+++ b/src/util/support/libkrb5support.exports
@@ -2,6 +2,9 @@ krb5int_key_register
krb5int_key_delete
krb5int_getspecific
krb5int_setspecific
+krb5int_mutex_lock_update_stats
+krb5int_mutex_unlock_update_stats
+krb5int_mutex_report_stats
krb5int_getaddrinfo
krb5int_freeaddrinfo
krb5int_gai_strerror
diff --git a/src/util/support/threads.c b/src/util/support/threads.c
index 7b061fdd74..c78751bd08 100644
--- a/src/util/support/threads.c
+++ b/src/util/support/threads.c
@@ -324,10 +324,22 @@ int krb5int_call_thread_support_init (void)
#include "cache-addrinfo.h"
+#ifdef DEBUG_THREADS_STATS
+#include <stdio.h>
+static FILE *stats_logfile;
+#endif
+
int krb5int_thread_support_init (void)
{
int err;
+#ifdef DEBUG_THREADS_STATS
+ /* stats_logfile = stderr; */
+ stats_logfile = fopen("/dev/tty", "w+");
+ if (stats_logfile == NULL)
+ stats_logfile = stderr;
+#endif
+
#ifndef ENABLE_THREADS
/* Nothing to do for TLS initialization. */
@@ -384,6 +396,103 @@ void krb5int_thread_support_fini (void)
#endif
+#ifdef DEBUG_THREADS_STATS
+ fflush(stats_logfile);
+ /* XXX Should close if not stderr, in case unloading library but
+ not exiting. */
+#endif
+
krb5int_fini_fac();
}
+#ifdef DEBUG_THREADS_STATS
+void
+k5_mutex_lock_update_stats(k5_debug_mutex_stats *m,
+ k5_mutex_stats_tmp startwait)
+{
+ k5_debug_time_t now;
+ k5_debug_timediff_t tdiff, tdiff2;
+
+ now = get_current_time();
+ (void) krb5int_call_thread_support_init();
+ m->count++;
+ m->time_acquired = now;
+ tdiff = timediff(now, startwait);
+ tdiff2 = tdiff * tdiff;
+ if (m->count == 1 || m->lockwait.valmin > tdiff)
+ m->lockwait.valmin = tdiff;
+ if (m->count == 1 || m->lockwait.valmax < tdiff)
+ m->lockwait.valmax = tdiff;
+ m->lockwait.valsum += tdiff;
+ m->lockwait.valsqsum += tdiff2;
+}
+
+void
+krb5int_mutex_unlock_update_stats(k5_debug_mutex_stats *m)
+{
+ k5_debug_time_t now = get_current_time();
+ k5_debug_timediff_t tdiff, tdiff2;
+ tdiff = timediff(now, m->time_acquired);
+ tdiff2 = tdiff * tdiff;
+ if (m->count == 1 || m->lockheld.valmin > tdiff)
+ m->lockheld.valmin = tdiff;
+ if (m->count == 1 || m->lockheld.valmax < tdiff)
+ m->lockheld.valmax = tdiff;
+ m->lockheld.valsum += tdiff;
+ m->lockheld.valsqsum += tdiff2;
+}
+
+#include <math.h>
+static inline double
+get_stddev(struct k5_timediff_stats sp, int count)
+{
+ long double mu, mu_squared, rho_squared;
+ mu = (long double) sp.valsum / count;
+ mu_squared = mu * mu;
+ /* SUM((x_i - mu)^2)
+ = SUM(x_i^2 - 2*mu*x_i + mu^2)
+ = SUM(x_i^2) - 2*mu*SUM(x_i) + N*mu^2
+
+ Standard deviation rho^2 = SUM(...) / N. */
+ rho_squared = (sp.valsqsum - 2 * mu * sp.valsum + count * mu_squared) / count;
+ return sqrt(rho_squared);
+}
+
+void
+krb5int_mutex_report_stats(k5_mutex_t *m)
+{
+ char *p;
+
+ /* Tweak this to only record data on "interesting" locks. */
+ if (m->stats.count < 10)
+ return;
+ if (m->stats.lockwait.valsum < 10 * m->stats.count)
+ return;
+
+ p = strrchr(m->loc_created.filename, '/');
+ if (p == NULL)
+ p = m->loc_created.filename;
+ else
+ p++;
+ fprintf(stats_logfile, "mutex @%p: created at line %d of %s\n",
+ (void *) m, m->loc_created.lineno, p);
+ if (m->stats.count == 0)
+ fprintf(stats_logfile, "\tnever locked\n");
+ else {
+ double sd_wait, sd_hold;
+ sd_wait = get_stddev(m->stats.lockwait, m->stats.count);
+ sd_hold = get_stddev(m->stats.lockheld, m->stats.count);
+ fprintf(stats_logfile,
+ "\tlocked %d time%s; wait %lu/%f/%lu/%fus, hold %lu/%f/%lu/%fus\n",
+ m->stats.count, m->stats.count == 1 ? "" : "s",
+ (unsigned long) m->stats.lockwait.valmin,
+ (double) m->stats.lockwait.valsum / m->stats.count,
+ (unsigned long) m->stats.lockwait.valmax,
+ sd_wait,
+ (unsigned long) m->stats.lockheld.valmin,
+ (double) m->stats.lockheld.valsum / m->stats.count,
+ (unsigned long) m->stats.lockheld.valmax,
+ sd_hold);
+ }
+}
+#endif
generated by cgit (git 2.34.1) at 2026-01-01 18:10:26 +0000