From owner-p4-projects@FreeBSD.ORG Mon Jun 26 00:26:07 2006 Return-Path: X-Original-To: p4-projects@freebsd.org Delivered-To: p4-projects@freebsd.org Received: by hub.freebsd.org (Postfix, from userid 32767) id 32CAC16A404; Mon, 26 Jun 2006 00:26:07 +0000 (UTC) X-Original-To: perforce@freebsd.org Delivered-To: perforce@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id E86E716A402 for ; Mon, 26 Jun 2006 00:26:06 +0000 (UTC) (envelope-from kmacy@freebsd.org) Received: from repoman.freebsd.org (repoman.freebsd.org [216.136.204.115]) by mx1.FreeBSD.org (Postfix) with ESMTP id 064CE447AC for ; Mon, 26 Jun 2006 00:25:46 +0000 (GMT) (envelope-from kmacy@freebsd.org) Received: from repoman.freebsd.org (localhost [127.0.0.1]) by repoman.freebsd.org (8.13.6/8.13.6) with ESMTP id k5Q0PgSk082427 for ; Mon, 26 Jun 2006 00:25:43 GMT (envelope-from kmacy@freebsd.org) Received: (from perforce@localhost) by repoman.freebsd.org (8.13.6/8.13.4/Submit) id k5Q0PgBv082424 for perforce@freebsd.org; Mon, 26 Jun 2006 00:25:42 GMT (envelope-from kmacy@freebsd.org) Date: Mon, 26 Jun 2006 00:25:42 GMT Message-Id: <200606260025.k5Q0PgBv082424@repoman.freebsd.org> X-Authentication-Warning: repoman.freebsd.org: perforce set sender to kmacy@freebsd.org using -f From: Kip Macy To: Perforce Change Reviews Cc: Subject: PERFORCE change 100004 for review X-BeenThere: p4-projects@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: p4 projects tree changes List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 26 Jun 2006 00:26:07 -0000 http://perforce.freebsd.org/chv.cgi?CH=100004 Change 100004 by kmacy@kmacy_storage:sun4v_work_sleepq on 2006/06/26 00:24:59 hoist large functions out of line for mutex profiling this yields a ~8% speedup on sun4v Affected files ... .. //depot/projects/kmacy_sun4v/src/sys/kern/kern_mutex.c#19 edit .. //depot/projects/kmacy_sun4v/src/sys/kern/subr_lock.c#3 edit .. //depot/projects/kmacy_sun4v/src/sys/sys/lock_profile.h#7 edit Differences ... ==== //depot/projects/kmacy_sun4v/src/sys/kern/kern_mutex.c#19 (text+ko) ==== @@ -257,13 +257,24 @@ if (v == 0) return (0); - bzero(mprof_buf, MPROF_HASH_SIZE); + bzero(mprof_buf, MPROF_HASH_SIZE*sizeof(*mprof_buf)); allocated_mprof_buf = 0; return (0); } SYSCTL_PROC(_debug_mutex_prof, OID_AUTO, reset, CTLTYPE_INT | CTLFLAG_RW, NULL, 0, reset_mutex_prof_stats, "I", "Reset mutex profiling statistics"); + +static inline void mutex_profile_init(void) +{ + 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|MTX_NOPROFILE); + } +} + #endif /* @@ -521,22 +532,27 @@ _mtx_trylockn_spin(struct mtx *m, uintptr_t tid, int n, const char *file, int line) { uintptr_t _tid = (uintptr_t)(tid); - int i, v; + int i, v, contested; + uint64_t waittime; KASSERT(LOCK_CLASS(&m->mtx_object) == &lock_class_mtx_spin, ("mtx_lock_spin() of sleep mutex %s @ %s:%d", m->mtx_object.lo_name, file, line)); + lock_profile_waitstart(&waittime); for (i = 0, v = 0; i < n; i++) { spinlock_enter(); v = _obtain_lock((m), _tid); - if (!v) + if (!v) { + lock_profile_obtain_lock_failed(&m->mtx_object, &contested); spinlock_exit(); - else { + } else { WITNESS_LOCK(&m->mtx_object, LOP_EXCLUSIVE, file, line); - break; + lock_profile_obtain_lock_success(&m->mtx_object, waittime, file, line); + return v; } } + lock_profile_update_wait(&m->mtx_object, waittime); return v; } ==== //depot/projects/kmacy_sun4v/src/sys/kern/subr_lock.c#3 (text+ko) ==== @@ -36,12 +36,14 @@ __FBSDID("$FreeBSD: src/sys/kern/subr_lock.c,v 1.4 2006/01/27 23:13:25 jhb Exp $"); #include "opt_ddb.h" +#include "opt_mprof.h" #include #include #include #include #include +#include #ifdef DDB #include @@ -55,6 +57,7 @@ &lock_class_sx, &lock_class_rw, }; +static u_int global_lock_id; void lock_init(struct lock_object *lock, struct lock_class *class, const char *name, @@ -78,6 +81,7 @@ lock->lo_name = name; lock->lo_type = type != NULL ? type : name; lock->lo_flags |= flags | LO_INITIALIZED; + lock->lo_id = atomic_fetchadd_int(&global_lock_id, 1); LOCK_LOG_INIT(lock, 0); WITNESS_INIT(lock); } @@ -113,3 +117,151 @@ class->lc_ddb_show(lock); } #endif + +#ifdef MUTEX_PROFILING +void _lock_profile_obtain_lock_success(struct lock_object *lo, uint64_t waittime, const char *file, int line) +{ + struct lock_profile_object *l = &lo->lo_profile_obj; + + /* don't reset the timer when/if recursing */ + if (l->lpo_acqtime == 0) { + l->lpo_filename = file; + l->lpo_lineno = line; + l->lpo_acqtime = rd(tick); /* substitute for more general TSC read */ + if (waittime) { + if (l->lpo_acqtime > waittime) + l->lpo_waittime = l->lpo_acqtime - waittime; + } + } +} + +void _lock_profile_update_wait(struct lock_object *lo, uint64_t waitstart) +{ + struct lock_profile_object *l = &lo->lo_profile_obj; + + if (mutex_prof_enable && waitstart) { + uint64_t now, waittime; + struct mutex_prof *mpp; + u_int hash; + const char *p = l->lpo_filename; + int collision = 0; + now = rd(tick); + if (now < waitstart) + return; + waittime = now - waitstart; + hash = (l->lpo_namehash * 31 * 31 + (uintptr_t)p * 31 + l->lpo_lineno) & MPROF_HASH_MASK; + + mpp = &mprof_buf[hash]; + while (mpp->name != NULL) { + if (mpp->line == l->lpo_lineno && + mpp->file == p && + mpp->namehash == l->lpo_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 = l->lpo_lineno; + mpp->name = lo->lo_name; + mpp->namehash = l->lpo_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); + mpp->cnt_wait += waittime; + MPROF_UNLOCK(hash); + } +} + +void _lock_profile_release_lock(struct lock_object *lo) +{ + struct lock_profile_object *l = &lo->lo_profile_obj; + + if (l->lpo_acqtime && !(lo->lo_flags & LO_NOPROFILE)) { + const char *unknown = "(unknown)"; + u_int64_t acqtime, now, waittime; + struct mutex_prof *mpp; + u_int hash; + const char *p = l->lpo_filename; + int collision = 0; + + now = rd(tick); + acqtime = l->lpo_acqtime; + waittime = l->lpo_waittime; + if (now <= acqtime) + return; + if (p == NULL || *p == '\0') + p = unknown; + hash = (l->lpo_namehash * 31 * 31 + (uintptr_t)p * 31 + l->lpo_lineno) & MPROF_HASH_MASK; + CTR5(KTR_SPARE1, "Hashing %s(%x) %s:%d to %d", l->lpo_name, l->lpo_namehash, p, l->lpo_lineno, hash); + mpp = &mprof_buf[hash]; + while (mpp->name != NULL) { + if (mpp->line == l->lpo_lineno && + mpp->file == p && + mpp->namehash == l->lpo_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 = l->lpo_lineno; + mpp->name = lo->lo_name; + mpp->namehash = l->lpo_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_wait += waittime; + 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 += l->lpo_contest_holding; + mpp->cnt_contest_locking += l->lpo_contest_locking; + MPROF_UNLOCK(hash); + + } + l->lpo_acqtime = 0; + l->lpo_waittime = 0; + l->lpo_contest_locking = 0; + l->lpo_contest_holding = 0; +} +#endif ==== //depot/projects/kmacy_sun4v/src/sys/sys/lock_profile.h#7 (text+ko) ==== @@ -4,6 +4,7 @@ #ifdef MUTEX_PROFILING #include #include +#include #ifndef MPROF_HASH_SIZE #define MPROF_HASH_SIZE 4096 @@ -40,6 +41,10 @@ extern int mutex_prof_rejected; extern int mutex_prof_collisions; +void _lock_profile_obtain_lock_success(struct lock_object *lo, uint64_t waittime, const char *file, int line); +void _lock_profile_update_wait(struct lock_object *lo, uint64_t waitstart); +void _lock_profile_release_lock(struct lock_object *lo); + static inline void lock_profile_init(struct lock_object *lo, const char *name) { const char *p; u_int hash = 0; @@ -74,19 +79,10 @@ } -static inline void mutex_profile_init(void) -{ - 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|MTX_NOPROFILE); - } -} - static inline void lock_profile_waitstart(uint64_t *waittime) { - *waittime = rd(tick); + if (mutex_prof_enable) + *waittime = rd(tick); } static inline void lock_profile_obtain_lock_failed(struct lock_object *lo, int *contested) @@ -100,104 +96,31 @@ static inline void lock_profile_obtain_lock_success(struct lock_object *lo, uint64_t waittime, const char *file, int line) { - struct lock_profile_object *l = &lo->lo_profile_obj; - - /* don't reset the timer when/if recursing */ - if (mutex_prof_enable && l->lpo_acqtime == 0) { - l->lpo_filename = file; - l->lpo_lineno = line; - l->lpo_acqtime = rd(tick); /* substitute for more general TSC read */ - if (waittime) { - if (l->lpo_acqtime > waittime) - l->lpo_waittime = l->lpo_acqtime - waittime; - } - } + if (mutex_prof_enable) + _lock_profile_obtain_lock_success(lo, waittime, file, line); +} + +static inline void lock_profile_update_wait(struct lock_object *lo, uint64_t waitstart) +{ + if (mutex_prof_enable) + _lock_profile_update_wait(lo, waitstart); } -static inline void lock_profile_release_lock(struct lock_object *lo) +static inline void lock_profile_release_lock(struct lock_object *lo) { struct lock_profile_object *l = &lo->lo_profile_obj; - - if (l->lpo_acqtime && !(lo->lo_flags & LO_NOPROFILE)) { - const char *unknown = "(unknown)"; - struct mutex_prof *mpp; - u_int64_t acqtime, now, waittime; - u_int hash; - const char *p = l->lpo_filename; - int collision = 0; - - now = rd(tick); - acqtime = l->lpo_acqtime; - waittime = l->lpo_waittime; - l->lpo_acqtime = 0; - l->lpo_waittime = 0; - if (now <= acqtime) - return; - if (p == NULL || *p == '\0') - p = unknown; - hash = (l->lpo_namehash * 31 * 31 + (uintptr_t)p * 31 + l->lpo_lineno) & MPROF_HASH_MASK; - CTR5(KTR_SPARE1, "Hashing %s(%x) %s:%d to %d", l->lpo_name, l->lpo_namehash, p, l->lpo_lineno, hash); - mpp = &mprof_buf[hash]; - while (mpp->name != NULL) { - if (mpp->line == l->lpo_lineno && - mpp->file == p && - mpp->namehash == l->lpo_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 = l->lpo_lineno; - mpp->name = lo->lo_name; - mpp->namehash = l->lpo_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_wait += waittime; - 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 += l->lpo_contest_holding; - l->lpo_contest_holding = 0; - mpp->cnt_contest_locking += l->lpo_contest_locking; - l->lpo_contest_locking = 0; - MPROF_UNLOCK(hash); - } + if (mutex_prof_enable || l->lpo_acqtime) + _lock_profile_release_lock(lo); } #else /* !MUTEX_PROFILING */ static inline void mutex_profile_init(void) {;} static inline void lock_profile_init(struct lock_object *lo, const char *name) {;} +static inline void lock_profile_destroy(struct lock_object *lo) {;} static inline void lock_profile_obtain_lock_failed(struct lock_object *m, int *contested) {;} static inline void lock_profile_obtain_lock_success(struct lock_object *m, const char *file, int line) {;} +static inline void lock_profile_update_wait(struct lock_object *lo, uint64_t waitstart) {;} static inline void lock_profile_release_lock(struct lock_object *m) {;} -static inline void lock_profile_destroy(struct lock_object *lo) {;} #endif /* !MUTEX_PROFILING */ #endif /* _SYS_LOCK_PROFILE_H_ */