Skip site navigation (1)Skip section navigation (2)
Date:      Mon, 26 Jun 2006 00:25:42 GMT
From:      Kip Macy <kmacy@FreeBSD.org>
To:        Perforce Change Reviews <perforce@freebsd.org>
Subject:   PERFORCE change 100004 for review
Message-ID:  <200606260025.k5Q0PgBv082424@repoman.freebsd.org>

next in thread | raw e-mail | index | archive | help
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 <sys/param.h>
 #include <sys/systm.h>
 #include <sys/ktr.h>
 #include <sys/linker_set.h>
 #include <sys/lock.h>
+#include <sys/lock_profile.h>
 
 #ifdef DDB
 #include <ddb/ddb.h>
@@ -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 <sys/stdint.h>
 #include <sys/ktr.h>
+#include <sys/mutex.h>
 
 #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_ */



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200606260025.k5Q0PgBv082424>