PERFORCE change 99891 for review
Kip Macy
kmacy at FreeBSD.org
Fri Jun 23 19:54:27 UTC 2006
http://perforce.freebsd.org/chv.cgi?CH=99891
Change 99891 by kmacy at kmacy_storage:sun4v_work_sleepq on 2006/06/23 19:53:42
re-factor MUTEX_PROFILING code into inline functions
re-enable (in a architecture dependent way) hold time collection
Affected files ...
.. //depot/projects/kmacy_sun4v/src/sys/kern/kern_mutex.c#11 edit
Differences ...
==== //depot/projects/kmacy_sun4v/src/sys/kern/kern_mutex.c#11 (text+ko) ====
@@ -156,24 +156,19 @@
#endif
#ifdef MUTEX_PROFILING
-SYSCTL_NODE(_debug, OID_AUTO, mutex, CTLFLAG_RD, NULL, "mutex debugging");
-SYSCTL_NODE(_debug_mutex, OID_AUTO, prof, CTLFLAG_RD, NULL, "mutex profiling");
-static int mutex_prof_enable = 0;
-SYSCTL_INT(_debug_mutex_prof, OID_AUTO, enable, CTLFLAG_RW,
- &mutex_prof_enable, 0, "Enable tracing of mutex holdtime/contention");
-static int mutex_prof_global = 1;
-SYSCTL_INT(_debug_mutex_prof, OID_AUTO, global, CTLFLAG_RW,
- &mutex_prof_global, 0, "Enable tracing of all mutexes");
+#include <sys/stdint.h>
+#ifndef MPROF_HASH_SIZE
+#define MPROF_HASH_SIZE 4096
+#define MPROF_HASH_MASK (MPROF_HASH_SIZE - 1)
+#endif
struct mutex_prof {
const char *name;
+ const char *file;
u_int namehash;
- const char *file;
int line;
-#if 0
uintmax_t cnt_max;
uintmax_t cnt_tot;
-#endif
uintmax_t cnt_cur;
uintmax_t cnt_contest_holding;
uintmax_t cnt_contest_locking;
@@ -183,10 +178,6 @@
* mprof_buf is a static pool of profiling records to avoid possible
* reentrance of the memory allocation functions.
*/
-#ifndef MPROF_HASH_SIZE
-#define MPROF_HASH_SIZE 4096
-#define MPROF_HASH_MASK (MPROF_HASH_SIZE - 1)
-#endif
static struct mutex_prof mprof_buf[MPROF_HASH_SIZE];
static int allocated_mprof_buf;
/* SWAG: sbuf size = avg stat. line size * number of locks */
@@ -199,9 +190,13 @@
#define MPROF_LOCK(hash) mtx_lock_spin(&mprof_locks[MPROF_LHASH(hash)])
#define MPROF_UNLOCK(hash) mtx_unlock_spin(&mprof_locks[MPROF_LHASH(hash)])
-
struct mtx mprof_locks[MPROF_LOCK_SIZE];
+SYSCTL_NODE(_debug, OID_AUTO, mutex, CTLFLAG_RD, NULL, "mutex debugging");
+SYSCTL_NODE(_debug_mutex, OID_AUTO, prof, CTLFLAG_RD, NULL, "mutex profiling");
+static int mutex_prof_enable = 0;
+SYSCTL_INT(_debug_mutex_prof, OID_AUTO, enable, CTLFLAG_RW,
+ &mutex_prof_enable, 0, "Enable tracing of mutex holdtime/contention");
static int mutex_prof_acquisitions;
SYSCTL_INT(_debug_mutex_prof, OID_AUTO, acquisitions, CTLFLAG_RD,
&mutex_prof_acquisitions, 0, "Number of mutex acquistions recorded");
@@ -226,17 +221,148 @@
&stack_scale, 0, "How often to sample stack traces");
#endif
+
+
+static inline void
+mtx_profile_init(struct mtx *m, const char *name) {
+ const char *p;
+ u_int hash = 0;
+
+ m->mtx_acqtime = 0;
+ m->mtx_filename = NULL;
+ m->mtx_lineno = 0;
+ m->mtx_contest_holding = 0;
+ m->mtx_contest_locking = 0;
+
+ /* Hash the mutex name to an int so we don't have to strcmp() it repeatedly */
+ for (p = name; *p != '\0'; p++)
+ hash = 31 * hash + *p;
+ m->mtx_namehash = hash;
+#if 0
+ if (opts & MTX_PROFILE)
+ m->mtx_stack = stack_create();
+#endif
+}
+
+static inline void
+mtx_profile_destroy(struct mtx *m)
+{
#if 0
-static u_int64_t
-nanoseconds(void)
+ if (m->mtx_object.lo_flags & LO_PROFILE)
+ stack_destroy(m->mtx_stack);
+#endif
+}
+
+static inline void
+mutex_profile_init(void)
{
- struct timespec tv;
+ int i;
+ /* Initialize the mutex profiling locks */
+ for (i = 0; i < MPROF_LOCK_SIZE; i++) {
+ mtx_init(&mprof_locks[i], "mprof lock",
+ NULL, MTX_SPIN|MTX_QUIET);
+ }
+}
- nanotime(&tv);
- return (tv.tv_sec * (u_int64_t)1000000000 + tv.tv_nsec);
+static inline void
+mtx_profile_obtain_lock_failed(struct mtx *m, int *contested)
+{
+ if (mutex_prof_enable) {
+ *contested = 1;
+ atomic_add_int(&m->mtx_contest_holding, 1);
+ }
}
+
+static inline void
+mtx_profile_obtain_lock_success(struct mtx *m, const char *file, int line)
+{
+ /* don't reset the timer when/if recursing */
+ if (mutex_prof_enable && m->mtx_acqtime == 0) {
+ m->mtx_filename = file;
+ m->mtx_lineno = line;
+ m->mtx_acqtime = rd(tick); /* substitute for more general TSC read */
+#if 0
+ ++mutex_prof_acquisitions;
#endif
+ }
+}
+
+static void
+mtx_profile_release_lock(struct mtx *m)
+{
+
+ if (m->mtx_acqtime) {
+ const char *unknown = "(unknown)";
+ struct mutex_prof *mpp;
+ u_int64_t acqtime, now;
+ u_int hash;
+ const char *p = m->mtx_filename;
+ int collision = 0;
+
+ now = rd(tick);
+ acqtime = m->mtx_acqtime;
+ m->mtx_acqtime = 0;
+ if (now <= acqtime)
+ return;
+ if (p == NULL || *p == '\0')
+ p = unknown;
+ hash = (m->mtx_namehash * 31 * 31 + (uintptr_t)p * 31 + m->mtx_lineno) & MPROF_HASH_MASK;
+ CTR5(KTR_SPARE1, "Hashing %s(%x) %s:%d to %d", mtx_name(m), m->mtx_namehash, p, m->mtx_lineno, hash);
+ mpp = &mprof_buf[hash];
+ while (mpp->name != NULL) {
+ if (mpp->line == m->mtx_lineno &&
+ mpp->file == p &&
+ mpp->namehash == m->mtx_namehash)
+ break;
+ /* If the mprof_hash entry is allocated to someone else, try the next one */
+ collision = 1;
+ CTR4(KTR_SPARE1, "Hash collision, %s:%d %s(%x)", mpp->file, mpp->line, mpp->name, mpp->namehash);
+ hash = (hash + 1) & MPROF_HASH_MASK;
+ mpp = &mprof_buf[hash];
+ }
+ if (mpp->name == NULL) {
+ int buf;
+ buf = atomic_fetchadd_int(&allocated_mprof_buf, 1);
+ /* Just exit if we cannot get a trace buffer */
+ if (buf >= MPROF_HASH_SIZE) {
+ ++mutex_prof_rejected;
+ return;
+ }
+ mpp->file = p;
+ mpp->line = m->mtx_lineno;
+ mpp->name = mtx_name(m);
+ mpp->namehash = m->mtx_namehash;
+ if (collision)
+ ++mutex_prof_collisions;
+ /* We might have raced someone else but who cares, they'll try again next time */
+ ++mutex_prof_records;
+ }
+ MPROF_LOCK(hash);
+ /*
+ * Record if the mutex has been held longer now than ever
+ * before.
+ */
+ if (now - acqtime > mpp->cnt_max)
+ mpp->cnt_max = now - acqtime;
+ mpp->cnt_tot += now - acqtime;
+ mpp->cnt_cur++;
+ /*
+ * There's a small race, really we should cmpxchg
+ * 0 with the current value, but that would bill
+ * the contention to the wrong lock instance if
+ * it followed this also.
+ */
+ mpp->cnt_contest_holding += m->mtx_contest_holding;
+ m->mtx_contest_holding = 0;
+ mpp->cnt_contest_locking += m->mtx_contest_locking;
+ m->mtx_contest_locking = 0;
+ MPROF_UNLOCK(hash);
+ }
+}
+
+
+
static int
dump_mutex_prof_stats(SYSCTL_HANDLER_ARGS)
{
@@ -260,18 +386,11 @@
p != NULL && strncmp(p, "../", 3) == 0; p += 3)
/* nothing */ ;
sbuf_printf(sb, "%6ju %12ju %11ju %5ju %12ju %12ju %s:%d (%s)\n",
-#if 0
mprof_buf[i].cnt_max / 1000,
mprof_buf[i].cnt_tot / 1000,
-#endif
- (uintmax_t)0,
- (uintmax_t)0,
mprof_buf[i].cnt_cur,
- (uintmax_t)0,
-#if 0
mprof_buf[i].cnt_cur == 0 ? (uintmax_t)0 :
mprof_buf[i].cnt_tot / (mprof_buf[i].cnt_cur * 1000),
-#endif
mprof_buf[i].cnt_contest_holding,
mprof_buf[i].cnt_contest_locking,
p, mprof_buf[i].line, mprof_buf[i].name);
@@ -313,6 +432,15 @@
}
SYSCTL_PROC(_debug_mutex_prof, OID_AUTO, reset, CTLTYPE_INT | CTLFLAG_RW,
NULL, 0, reset_mutex_prof_stats, "I", "Reset mutex profiling statistics");
+
+#else
+static inline void mtx_profile_init(struct mtx *m, const char *name) {;}
+static inline void mtx_profile_destroy(struct mtx *m) {;}
+static inline void mtx_profile_obtain_lock_failed(struct mtx *m, int *contested) {;}
+static inline void mtx_profile_obtain_lock_success(struct mtx *m, const char *file, int line) {;}
+static inline void mtx_profile_release_lock(struct mtx *m) {;}
+
+static inline void mutex_profile_init(void) {;}
#endif
/*
@@ -333,17 +461,7 @@
LOCK_LOG_LOCK("LOCK", &m->mtx_object, opts, m->mtx_recurse, file,
line);
WITNESS_LOCK(&m->mtx_object, opts | LOP_EXCLUSIVE, file, line);
-#ifdef MUTEX_PROFILING
- /* don't reset the timer when/if recursing */
- if (mutex_prof_enable == 1 && mutex_prof_global && m->mtx_acqtime == 0) {
- m->mtx_filename = file;
- m->mtx_lineno = line;
- m->mtx_acqtime = 1;
-#if 0
- ++mutex_prof_acquisitions;
-#endif
- }
-#endif
+ mtx_profile_obtain_lock_success(m, file, line);
}
void
@@ -358,79 +476,8 @@
LOCK_LOG_LOCK("UNLOCK", &m->mtx_object, opts, m->mtx_recurse, file,
line);
mtx_assert(m, MA_OWNED);
-#ifdef MUTEX_PROFILING
- if (mutex_prof_global && m->mtx_acqtime != 0) {
- const char *unknown = "(unknown)";
- struct mutex_prof *mpp;
- u_int64_t acqtime, now;
- u_int hash;
- const char *p = m->mtx_filename;
- int collision = 0;
- now = 2;
- acqtime = m->mtx_acqtime;
- m->mtx_acqtime = 0;
- if (now <= acqtime)
- goto out;
- if (p == NULL || *p == '\0')
- p = unknown;
- hash = (m->mtx_namehash * 31 * 31 + (uintptr_t)p * 31 + m->mtx_lineno) & MPROF_HASH_MASK;
- CTR5(KTR_SPARE1, "Hashing %s(%x) %s:%d to %d", mtx_name(m), m->mtx_namehash, p, m->mtx_lineno, hash);
- mpp = &mprof_buf[hash];
- while (mpp->name != NULL) {
- if (mpp->line == m->mtx_lineno &&
- mpp->file == p &&
- mpp->namehash == m->mtx_namehash)
- break;
- /* If the mprof_hash entry is allocated to someone else, try the next one */
- collision = 1;
- CTR4(KTR_SPARE1, "Hash collision, %s:%d %s(%x)", mpp->file, mpp->line, mpp->name, mpp->namehash);
- hash = (hash + 1) & MPROF_HASH_MASK;
- mpp = &mprof_buf[hash];
- }
- if (mpp->name == NULL) {
- int buf;
-
- buf = atomic_fetchadd_int(&allocated_mprof_buf, 1);
- /* Just exit if we cannot get a trace buffer */
- if (buf >= MPROF_HASH_SIZE) {
- ++mutex_prof_rejected;
- goto out;
- }
- mpp->file = p;
- mpp->line = m->mtx_lineno;
- mpp->name = mtx_name(m);
- mpp->namehash = m->mtx_namehash;
- if (collision)
- ++mutex_prof_collisions;
- /* We might have raced someone else but who cares, they'll try again next time */
- ++mutex_prof_records;
- }
- MPROF_LOCK(hash);
- /*
- * Record if the mutex has been held longer now than ever
- * before.
- */
-#if 0
- if (now - acqtime > mpp->cnt_max)
- mpp->cnt_max = now - acqtime;
- mpp->cnt_tot += now - acqtime;
-#endif
- mpp->cnt_cur++;
- /*
- * There's a small race, really we should cmpxchg
- * 0 with the current value, but that would bill
- * the contention to the wrong lock instance if
- * it followed this also.
- */
- mpp->cnt_contest_holding += m->mtx_contest_holding;
- m->mtx_contest_holding = 0;
- mpp->cnt_contest_locking += m->mtx_contest_locking;
- m->mtx_contest_locking = 0;
- MPROF_UNLOCK(hash);
- }
-out:
-#endif
+ mtx_profile_release_lock(m);
_rel_sleep_lock(m, curthread, opts, file, line);
}
@@ -514,9 +561,7 @@
int cont_logged = 0;
#endif
#endif
-#ifdef MUTEX_PROFILING
- int contested, oldhold, fine_profiling = 0;
-#endif
+ int contested;
if (mtx_owned(m)) {
KASSERT((m->mtx_object.lo_flags & LO_RECURSABLE) != 0,
@@ -534,35 +579,8 @@
"_mtx_lock_sleep: %s contested (lock=%p) at %s:%d",
m->mtx_object.lo_name, (void *)m->mtx_lock, file, line);
-#ifdef MUTEX_PROFILING
- contested = 0;
- if (m->mtx_object.lo_flags & LO_PROFILE)
- fine_profiling = 1;
-#endif
while (!_obtain_lock(m, tid)) {
-#ifdef MUTEX_PROFILING
- if (mutex_prof_global) {
- contested = 1;
- atomic_add_int(&m->mtx_contest_holding, 1);
- } else if (fine_profiling && !contested) {
- contested = 1;
- oldhold = atomic_fetchadd_int(&m->mtx_contest_holding, 1);
-#if 0
- if (!((oldhold + 1) % stack_scale)) {
- mtx_lock_spin(&mprof_mtx);
- stack_save(&mtx_stack);
- CTR2(KTR_CONTENTION, "cont_hold (%d) of %s", oldhold, m->mtx_object.lo_name);
- CTRSTACK(KTR_CONTENTION, &mtx_stack, 4, 0);
- mtx_unlock_spin(&mprof_mtx);
- }
- CTR3(KTR_CONTENTION,
- "%s held by %s:%d",
- m->mtx_object.lo_name,
- m->mtx_filename,
- m->mtx_lineno);
-#endif
- }
-#endif
+ mtx_profile_obtain_lock_failed(m, &contested);
turnstile_lock(&m->mtx_object);
v = m->mtx_lock;
@@ -645,7 +663,7 @@
#endif
#endif
#ifdef MUTEX_PROFILING
- if (fine_profiling || mutex_prof_global) {
+ if (mutex_prof_enable) {
m->mtx_contest_locking = contested;
atomic_store_rel_int(&m->mtx_contest_holding,0);
}
@@ -920,10 +938,6 @@
{
struct lock_class *class;
int flags;
-#ifdef MUTEX_PROFILING
- const char *p;
- u_int hash = 0;
-#endif
MPASS((opts & ~(MTX_SPIN | MTX_QUIET | MTX_RECURSE |
MTX_NOWITNESS | MTX_DUPOK)) == 0);
@@ -953,23 +967,8 @@
/* Initialize mutex. */
m->mtx_lock = MTX_UNOWNED;
m->mtx_recurse = 0;
-#ifdef MUTEX_PROFILING
- m->mtx_acqtime = 0;
- m->mtx_filename = NULL;
- m->mtx_lineno = 0;
- m->mtx_contest_holding = 0;
- m->mtx_contest_locking = 0;
- /* Hash the mutex name to an int so we don't have to strcmp() it repeatedly */
- for (p = name; *p != '\0'; p++)
- hash = 31 * hash + *p;
- m->mtx_namehash = hash;
-#if 0
- if (opts & MTX_PROFILE)
- m->mtx_stack = stack_create();
-#endif
-#endif
-
+ mtx_profile_init(m, name);
lock_init(&m->mtx_object, class, name, type, flags);
}
@@ -996,14 +995,8 @@
WITNESS_UNLOCK(&m->mtx_object, LOP_EXCLUSIVE, __FILE__,
__LINE__);
}
-
-#ifdef MUTEX_PROFILING
-#if 0
- if (m->mtx_object.lo_flags & LO_PROFILE)
- stack_destroy(m->mtx_stack);
-#endif
-#endif
-
+
+ mtx_profile_destroy(m);
lock_destroy(&m->mtx_object);
}
@@ -1015,20 +1008,12 @@
void
mutex_init(void)
{
-#ifdef MUTEX_PROFILING
- int i;
-#endif
-
/* Setup turnstiles so that sleep mutexes work. */
init_turnstiles();
-#ifdef MUTEX_PROFILING
- /* Initialize the mutex profiling locks */
- for (i = 0; i < MPROF_LOCK_SIZE; i++) {
- mtx_init(&mprof_locks[i], "mprof lock",
- NULL, MTX_SPIN|MTX_QUIET);
- }
-#endif
+ printf("calling profile init\n");
+ mutex_profile_init();
+ printf("called profile init\n");
/*
* Initialize mutexes.
More information about the p4-projects
mailing list