Index: kern/kern_mutex.c =================================================================== RCS file: /data/ncvs/src/sys/kern/kern_mutex.c,v retrieving revision 1.133 diff -u -r1.133 kern_mutex.c --- kern/kern_mutex.c 5 Jan 2004 23:09:51 -0000 1.133 +++ kern/kern_mutex.c 24 Jan 2004 03:41:43 -0000 @@ -105,6 +105,8 @@ uintmax_t cnt_max; uintmax_t cnt_tot; uintmax_t cnt_cur; + uintmax_t cnt_contest_holding; + uintmax_t cnt_contest_locking; struct mutex_prof *next; }; @@ -169,8 +171,8 @@ retry_sbufops: sb = sbuf_new(NULL, NULL, MPROF_SBUF_SIZE * multiplier, SBUF_FIXEDLEN); - sbuf_printf(sb, "%6s %12s %11s %5s %s\n", - "max", "total", "count", "avg", "name"); + sbuf_printf(sb, "%6s %12s %11s %5s %12s %12s %s\n", + "max", "total", "count", "avg", "cnt_hold", "cnt_lock", "name"); /* * XXX this spinlock seems to be by far the largest perpetrator * of spinlock latency (1.6 msec on an Athlon1600 was recorded @@ -179,12 +181,14 @@ */ mtx_lock_spin(&mprof_mtx); for (i = 0; i < first_free_mprof_buf; ++i) { - sbuf_printf(sb, "%6ju %12ju %11ju %5ju %s:%d (%s)\n", + sbuf_printf(sb, "%6ju %12ju %11ju %5ju %12ju %12ju %s:%d (%s)\n", mprof_buf[i].cnt_max / 1000, mprof_buf[i].cnt_tot / 1000, mprof_buf[i].cnt_cur, mprof_buf[i].cnt_cur == 0 ? (uintmax_t)0 : mprof_buf[i].cnt_tot / (mprof_buf[i].cnt_cur * 1000), + mprof_buf[i].cnt_contest_holding, + mprof_buf[i].cnt_contest_locking, mprof_buf[i].file, mprof_buf[i].line, mprof_buf[i].name); if (sbuf_overflowed(sb)) { mtx_unlock_spin(&mprof_mtx); @@ -291,6 +295,16 @@ 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; unlock: mtx_unlock_spin(&mprof_mtx); } @@ -381,6 +395,9 @@ #ifdef KTR int cont_logged = 0; #endif +#ifdef MUTEX_PROFILING + int contested; +#endif if (mtx_owned(m)) { KASSERT((m->mtx_object.lo_flags & LO_RECURSABLE) != 0, @@ -398,8 +415,14 @@ "_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; +#endif while (!_obtain_lock(m, td)) { - +#ifdef MUTEX_PROFILING + contested = 1; + atomic_add_int(&m->mtx_contest_holding, 1); +#endif ts = turnstile_lookup(&m->mtx_object); v = m->mtx_lock; @@ -425,7 +448,7 @@ MPASS(ts != NULL); m->mtx_lock = (uintptr_t)td | MTX_CONTESTED; turnstile_claim(ts); - return; + break; } /* @@ -488,6 +511,11 @@ "contention end: %s acquired by %p at %s:%d", m->mtx_object.lo_name, td, file, line); } +#endif +#ifdef MUTEX_PROFILING + if (contested) + m->mtx_contest_locking++; + m->mtx_contest_holding = 0; #endif return; } Index: kern/sys_process.c =================================================================== RCS file: /data/ncvs/src/sys/kern/sys_process.c,v retrieving revision 1.115 diff -u -r1.115 sys_process.c --- kern/sys_process.c 9 Oct 2003 10:17:16 -0000 1.115 +++ kern/sys_process.c 9 Jan 2004 21:40:26 -0000 @@ -564,6 +564,7 @@ } p->p_flag &= ~(P_TRACED | P_WAITED); p->p_oppid = 0; + SIGDELSET(p->p_siglist, SIGTRAP); /* should we send SIGCHLD? */ } Index: sys/_mutex.h =================================================================== RCS file: /data/ncvs/src/sys/sys/_mutex.h,v retrieving revision 1.10 diff -u -r1.10 _mutex.h --- sys/_mutex.h 11 Nov 2003 22:07:29 -0000 1.10 +++ sys/_mutex.h 23 Jan 2004 22:15:21 -0000 @@ -47,6 +47,15 @@ u_int64_t mtx_acqtime; const char *mtx_filename; int mtx_lineno; + /* + * Fields relating to measuring contention on mutexes. + * holding must be accessed atomically since it's + * modified by threads that don't yet hold the mutex. + * locking is only modified and referenced while + * the mutex is held. + */ + u_int mtx_contest_holding; + u_int mtx_contest_locking; #endif };