Index: cddl/contrib/opensolaris/cmd/lockstat/lockstat.c =================================================================== --- cddl/contrib/opensolaris/cmd/lockstat/lockstat.c +++ cddl/contrib/opensolaris/cmd/lockstat/lockstat.c @@ -149,18 +149,22 @@ "lockstat:::spin-spin" }, { 'C', "Lock", "Thread lock spin", "nsec", "lockstat:::thread-spin" }, - { 'C', "Lock", "R/W writer blocked by writer", "nsec", - "lockstat:::rw-block", "arg2 == 0 && arg3 == 1" }, - { 'C', "Lock", "R/W writer blocked by readers", "nsec", - "lockstat:::rw-block", "arg2 == 0 && arg3 == 0 && arg4" }, - { 'C', "Lock", "R/W reader blocked by writer", "nsec", - "lockstat:::rw-block", "arg2 != 0 && arg3 == 1" }, - { 'C', "Lock", "R/W reader blocked by write wanted", "nsec", - "lockstat:::rw-block", "arg2 != 0 && arg3 == 0 && arg4" }, - { 'C', "Lock", "Unknown event (type 8)", "units" }, - { 'C', "Lock", "Unknown event (type 9)", "units" }, - { 'C', "Lock", "Unknown event (type 10)", "units" }, - { 'C', "Lock", "Unknown event (type 11)", "units" }, + { 'C', "Lock", "R/W writer spin", "nsec", + "lockstat::rw_wlock:rw-spin" }, + { 'C', "Lock", "R/W writer block", "nsec", + "lockstat::rw_wlock:rw-block" }, + { 'C', "Lock", "R/W reader spin", "nsec", + "lockstat::rw_rlock:rw-spin" }, + { 'C', "Lock", "R/W reader block", "nsec", + "lockstat::rw_rlock:rw-block" }, + { 'C', "Lock", "SX shared spin", "nsec", + "lockstat::sx_slock:sx-spin" }, + { 'C', "Lock", "SX shared block", "nsec", + "lockstat::sx_slock:sx-block" }, + { 'C', "Lock", "SX exclsuive spin", "nsec", + "lockstat::sx_xlock:sx-spin" }, + { 'C', "Lock", "SX exclsuive block", "nsec", + "lockstat::sx_xlock:sx-block" }, { 'C', "Lock", "Unknown event (type 12)", "units" }, { 'C', "Lock", "Unknown event (type 13)", "units" }, { 'C', "Lock", "Unknown event (type 14)", "units" }, @@ -188,13 +192,17 @@ "lockstat:::spin-release", NULL, "lockstat:::spin-acquire" }, { 'H', "Lock", "R/W writer hold", "nsec", - "lockstat:::rw-release", "arg1 == 0", - "lockstat:::rw-acquire" }, + "lockstat::rw_wunlock:rw-release", NULL, + "lockstat::rw_wlock:rw-acquire" }, { 'H', "Lock", "R/W reader hold", "nsec", - "lockstat:::rw-release", "arg1 != 0", - "lockstat:::rw-acquire" }, - { 'H', "Lock", "Unknown event (type 36)", "units" }, - { 'H', "Lock", "Unknown event (type 37)", "units" }, + "lockstat::rw_runlock:rw-release", NULL, + "lockstat::rw_rlock:rw-acquire" }, + { 'H', "Lock", "SX shared hold", "nsec", + "lockstat::sx_sunlock:sx-release", NULL, + "lockstat::sx_slock:sx-acquire" }, + { 'H', "Lock", "SX exclusive hold", "nsec", + "lockstat::sx_xunlock:sx-release", NULL, + "lockstat::sx_xlock:sx-acquire" }, { 'H', "Lock", "Unknown event (type 38)", "units" }, { 'H', "Lock", "Unknown event (type 39)", "units" }, { 'H', "Lock", "Unknown event (type 40)", "units" }, Index: sys/kern/kern_mutex.c =================================================================== --- sys/kern/kern_mutex.c +++ sys/kern/kern_mutex.c @@ -384,6 +384,7 @@ uint64_t spin_cnt = 0; uint64_t sleep_cnt = 0; int64_t sleep_time = 0; + int64_t all_time = 0; #endif if (SCHEDULER_STOPPED()) @@ -414,6 +415,9 @@ CTR4(KTR_LOCK, "_mtx_lock_sleep: %s contested (lock=%p) at %s:%d", m->lock_object.lo_name, (void *)m->mtx_lock, file, line); +#ifdef KDTRACE_HOOKS + all_time -= lockstat_nsecs(); +#endif while (!_mtx_obtain_lock(m, tid)) { #ifdef KDTRACE_HOOKS @@ -517,6 +521,9 @@ sleep_cnt++; #endif } +#ifdef KDTRACE_HOOKS + all_time += lockstat_nsecs(); +#endif #ifdef KTR if (cont_logged) { CTR4(KTR_CONTENTION, @@ -534,7 +541,7 @@ * Only record the loops spinning and not sleeping. */ if (spin_cnt > sleep_cnt) - LOCKSTAT_RECORD1(LS_MTX_LOCK_SPIN, m, (spin_cnt - sleep_cnt)); + LOCKSTAT_RECORD1(LS_MTX_LOCK_SPIN, m, (all_time - sleep_time)); #endif } @@ -574,6 +581,9 @@ int contested = 0; uint64_t waittime = 0; #endif +#ifdef KDTRACE_HOOKS + int64_t spin_time = 0; +#endif if (SCHEDULER_STOPPED()) return; @@ -589,6 +599,9 @@ PMC_SOFT_CALL( , , lock, failed); #endif lock_profile_obtain_lock_failed(&m->lock_object, &contested, &waittime); +#ifdef KDTRACE_HOOKS + spin_time -= lockstat_nsecs(); +#endif while (!_mtx_obtain_lock(m, tid)) { /* Give interrupts a chance while we spin. */ @@ -606,6 +619,9 @@ } spinlock_enter(); } +#ifdef KDTRACE_HOOKS + spin_time += lockstat_nsecs(); +#endif if (LOCK_LOG_TEST(&m->lock_object, opts)) CTR1(KTR_LOCK, "_mtx_lock_spin: %p spin done", m); @@ -614,7 +630,7 @@ LOCKSTAT_PROFILE_OBTAIN_LOCK_SUCCESS(LS_MTX_SPIN_LOCK_ACQUIRE, m, contested, waittime, (file), (line)); - LOCKSTAT_RECORD1(LS_MTX_SPIN_LOCK_SPIN, m, i); + LOCKSTAT_RECORD1(LS_MTX_SPIN_LOCK_SPIN, m, spin_time); } #endif /* SMP */ @@ -629,7 +645,7 @@ uint64_t waittime = 0; #endif #ifdef KDTRACE_HOOKS - uint64_t spin_cnt = 0; + int64_t spin_time = 0; #endif i = 0; @@ -638,6 +654,9 @@ if (SCHEDULER_STOPPED()) return; +#ifdef KDTRACE_HOOKS + spin_time -= lockstat_nsecs(); +#endif for (;;) { retry: spinlock_enter(); @@ -654,9 +673,6 @@ WITNESS_CHECKORDER(&m->lock_object, opts | LOP_NEWORDER | LOP_EXCLUSIVE, file, line, NULL); while (!_mtx_obtain_lock(m, tid)) { -#ifdef KDTRACE_HOOKS - spin_cnt++; -#endif if (m->mtx_lock == tid) { m->mtx_recurse++; break; @@ -685,17 +701,17 @@ if (m == td->td_lock) break; __mtx_unlock_spin(m); /* does spinlock_exit() */ + } #ifdef KDTRACE_HOOKS - spin_cnt++; + spin_time += lockstat_nsecs(); #endif - } if (m->mtx_recurse == 0) LOCKSTAT_PROFILE_OBTAIN_LOCK_SUCCESS(LS_MTX_SPIN_LOCK_ACQUIRE, m, contested, waittime, (file), (line)); LOCK_LOG_LOCK("LOCK", &m->lock_object, opts, m->mtx_recurse, file, line); WITNESS_LOCK(&m->lock_object, opts | LOP_EXCLUSIVE, file, line); - LOCKSTAT_RECORD1(LS_THREAD_LOCK_SPIN, m, spin_cnt); + LOCKSTAT_RECORD1(LS_THREAD_LOCK_SPIN, m, spin_time); } struct mtx * Index: sys/kern/kern_rwlock.c =================================================================== --- sys/kern/kern_rwlock.c +++ sys/kern/kern_rwlock.c @@ -355,6 +355,7 @@ uint64_t spin_cnt = 0; uint64_t sleep_cnt = 0; int64_t sleep_time = 0; + int64_t all_time = 0; #endif if (SCHEDULER_STOPPED()) @@ -372,6 +373,9 @@ rw->lock_object.lo_name, file, line)); WITNESS_CHECKORDER(&rw->lock_object, LOP_NEWORDER, file, line, NULL); +#ifdef KDTRACE_HOOKS + all_time -= lockstat_nsecs(); +#endif for (;;) { #ifdef KDTRACE_HOOKS spin_cnt++; @@ -534,6 +538,9 @@ CTR2(KTR_LOCK, "%s: %p resuming from turnstile", __func__, rw); } +#ifdef KDTRACE_HOOKS + all_time += lockstat_nsecs(); +#endif /* * TODO: acquire "owner of record" here. Here be turnstile dragons @@ -554,7 +561,7 @@ * Record only the loops spinning and not sleeping. */ if (spin_cnt > sleep_cnt) - LOCKSTAT_RECORD1(LS_RW_RLOCK_SPIN, rw, (spin_cnt - sleep_cnt)); + LOCKSTAT_RECORD1(LS_RW_RLOCK_SPIN, rw, (all_time - sleep_time)); #endif } @@ -730,6 +737,7 @@ uint64_t spin_cnt = 0; uint64_t sleep_cnt = 0; int64_t sleep_time = 0; + int64_t all_time = 0; #endif if (SCHEDULER_STOPPED()) @@ -751,6 +759,9 @@ CTR5(KTR_LOCK, "%s: %s contested (lock=%p) at %s:%d", __func__, rw->lock_object.lo_name, (void *)rw->rw_lock, file, line); +#ifdef KDTRACE_HOOKS + all_time -= lockstat_nsecs(); +#endif while (!_rw_write_lock(rw, tid)) { #ifdef KDTRACE_HOOKS spin_cnt++; @@ -888,6 +899,9 @@ spintries = 0; #endif } +#ifdef KDTRACE_HOOKS + all_time += lockstat_nsecs(); +#endif LOCKSTAT_PROFILE_OBTAIN_LOCK_SUCCESS(LS_RW_WLOCK_ACQUIRE, rw, contested, waittime, file, line); #ifdef KDTRACE_HOOKS @@ -898,7 +912,7 @@ * Record only the loops spinning and not sleeping. */ if (spin_cnt > sleep_cnt) - LOCKSTAT_RECORD1(LS_RW_WLOCK_SPIN, rw, (spin_cnt - sleep_cnt)); + LOCKSTAT_RECORD1(LS_RW_WLOCK_SPIN, rw, (all_time - sleep_time)); #endif } Index: sys/kern/kern_sx.c =================================================================== --- sys/kern/kern_sx.c +++ sys/kern/kern_sx.c @@ -512,6 +512,7 @@ uint64_t spin_cnt = 0; uint64_t sleep_cnt = 0; int64_t sleep_time = 0; + int64_t all_time = 0; #endif if (SCHEDULER_STOPPED()) @@ -533,6 +534,9 @@ CTR5(KTR_LOCK, "%s: %s contested (lock=%p) at %s:%d", __func__, sx->lock_object.lo_name, (void *)sx->sx_lock, file, line); +#ifdef KDTRACE_HOOKS + all_time -= lockstat_nsecs(); +#endif while (!atomic_cmpset_acq_ptr(&sx->sx_lock, SX_LOCK_UNLOCKED, tid)) { #ifdef KDTRACE_HOOKS spin_cnt++; @@ -705,6 +709,9 @@ CTR2(KTR_LOCK, "%s: %p resuming from sleep queue", __func__, sx); } +#ifdef KDTRACE_HOOKS + all_time += lockstat_nsecs(); +#endif GIANT_RESTORE(); if (!error) @@ -714,7 +721,7 @@ if (sleep_time) LOCKSTAT_RECORD1(LS_SX_XLOCK_BLOCK, sx, sleep_time); if (spin_cnt > sleep_cnt) - LOCKSTAT_RECORD1(LS_SX_XLOCK_SPIN, sx, (spin_cnt - sleep_cnt)); + LOCKSTAT_RECORD1(LS_SX_XLOCK_SPIN, sx, (all_time - sleep_time)); #endif return (error); } @@ -804,11 +811,16 @@ uint64_t spin_cnt = 0; uint64_t sleep_cnt = 0; int64_t sleep_time = 0; + int64_t all_time = 0; #endif if (SCHEDULER_STOPPED()) return (0); +#ifdef KDTRACE_HOOKS + all_time -= lockstat_nsecs(); +#endif + /* * As with rwlocks, we don't make any attempt to try to block * shared locks once there is an exclusive waiter. @@ -958,6 +970,9 @@ CTR2(KTR_LOCK, "%s: %p resuming from sleep queue", __func__, sx); } +#ifdef KDTRACE_HOOKS + all_time += lockstat_nsecs(); +#endif if (error == 0) LOCKSTAT_PROFILE_OBTAIN_LOCK_SUCCESS(LS_SX_SLOCK_ACQUIRE, sx, contested, waittime, file, line); @@ -965,7 +980,7 @@ if (sleep_time) LOCKSTAT_RECORD1(LS_SX_XLOCK_BLOCK, sx, sleep_time); if (spin_cnt > sleep_cnt) - LOCKSTAT_RECORD1(LS_SX_XLOCK_SPIN, sx, (spin_cnt - sleep_cnt)); + LOCKSTAT_RECORD1(LS_SX_XLOCK_SPIN, sx, (all_time - sleep_time)); #endif GIANT_RESTORE(); return (error);