From owner-svn-src-head@freebsd.org Wed Aug 21 23:44:00 2019 Return-Path: Delivered-To: svn-src-head@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id 13F40D79B0; Wed, 21 Aug 2019 23:44:00 +0000 (UTC) (envelope-from markj@FreeBSD.org) Received: from mxrelay.nyi.freebsd.org (mxrelay.nyi.freebsd.org [IPv6:2610:1c1:1:606c::19:3]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) server-signature RSA-PSS (4096 bits) client-signature RSA-PSS (4096 bits) client-digest SHA256) (Client CN "mxrelay.nyi.freebsd.org", Issuer "Let's Encrypt Authority X3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 46DPPr0GPTz3FRT; Wed, 21 Aug 2019 23:44:00 +0000 (UTC) (envelope-from markj@FreeBSD.org) Received: from repo.freebsd.org (repo.freebsd.org [IPv6:2610:1c1:1:6068::e6a:0]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mxrelay.nyi.freebsd.org (Postfix) with ESMTPS id 0433623556; Wed, 21 Aug 2019 23:44:00 +0000 (UTC) (envelope-from markj@FreeBSD.org) Received: from repo.freebsd.org ([127.0.1.37]) by repo.freebsd.org (8.15.2/8.15.2) with ESMTP id x7LNhxYN058388; Wed, 21 Aug 2019 23:43:59 GMT (envelope-from markj@FreeBSD.org) Received: (from markj@localhost) by repo.freebsd.org (8.15.2/8.15.2/Submit) id x7LNhxkh058383; Wed, 21 Aug 2019 23:43:59 GMT (envelope-from markj@FreeBSD.org) Message-Id: <201908212343.x7LNhxkh058383@repo.freebsd.org> X-Authentication-Warning: repo.freebsd.org: markj set sender to markj@FreeBSD.org using -f From: Mark Johnston Date: Wed, 21 Aug 2019 23:43:59 +0000 (UTC) To: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org Subject: svn commit: r351361 - in head: cddl/contrib/opensolaris/cmd/lockstat share/man/man4 sys/kern sys/sys X-SVN-Group: head X-SVN-Commit-Author: markj X-SVN-Commit-Paths: in head: cddl/contrib/opensolaris/cmd/lockstat share/man/man4 sys/kern sys/sys X-SVN-Commit-Revision: 351361 X-SVN-Commit-Repository: base MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-BeenThere: svn-src-head@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: SVN commit messages for the src tree for head/-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 21 Aug 2019 23:44:00 -0000 Author: markj Date: Wed Aug 21 23:43:58 2019 New Revision: 351361 URL: https://svnweb.freebsd.org/changeset/base/351361 Log: Add lockmgr(9) probes to the lockstat DTrace provider. They follow the conventions set by rw and sx lock probes. There is an additional lockstat:::lockmgr-disown probe. Update lockstat(1) to report on contention and hold events for lockmgr locks. Document the new probes in dtrace_lockstat.4, and deduplicate some of the existing probe descriptions. Reviewed by: mjg MFC after: 1 week Sponsored by: The FreeBSD Foundation Differential Revision: https://reviews.freebsd.org/D21355 Modified: head/cddl/contrib/opensolaris/cmd/lockstat/lockstat.c head/share/man/man4/dtrace_lockstat.4 head/sys/kern/kern_lock.c head/sys/kern/kern_lockstat.c head/sys/sys/lockstat.h Modified: head/cddl/contrib/opensolaris/cmd/lockstat/lockstat.c ============================================================================== --- head/cddl/contrib/opensolaris/cmd/lockstat/lockstat.c Wed Aug 21 23:24:40 2019 (r351360) +++ head/cddl/contrib/opensolaris/cmd/lockstat/lockstat.c Wed Aug 21 23:43:58 2019 (r351361) @@ -158,29 +158,33 @@ static ls_event_info_t g_event_info[LS_MAX_EVENTS] = { { '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" }, + "lockstat:::rw-block", "arg2 == 1 && arg3 == 1" }, { 'C', "Lock", "R/W reader blocked by write wanted", "nsec", - "lockstat:::rw-block", "arg2 != 0 && arg3 == 0 && arg4" }, + "lockstat:::rw-block", "arg2 == 1 && arg3 == 0 && arg4" }, { 'C', "Lock", "R/W writer spin on writer", "nsec", "lockstat:::rw-spin", "arg2 == 0 && arg3 == 1" }, { 'C', "Lock", "R/W writer spin on readers", "nsec", "lockstat:::rw-spin", "arg2 == 0 && arg3 == 0 && arg4" }, { 'C', "Lock", "R/W reader spin on writer", "nsec", - "lockstat:::rw-spin", "arg2 != 0 && arg3 == 1" }, + "lockstat:::rw-spin", "arg2 == 1 && arg3 == 1" }, { 'C', "Lock", "R/W reader spin on write wanted", "nsec", - "lockstat:::rw-spin", "arg2 != 0 && arg3 == 0 && arg4" }, + "lockstat:::rw-spin", "arg2 == 1 && arg3 == 0 && arg4" }, { 'C', "Lock", "SX exclusive block", "nsec", "lockstat:::sx-block", "arg2 == 0" }, { 'C', "Lock", "SX shared block", "nsec", - "lockstat:::sx-block", "arg2 != 0" }, + "lockstat:::sx-block", "arg2 == 1" }, { 'C', "Lock", "SX exclusive spin", "nsec", "lockstat:::sx-spin", "arg2 == 0" }, { 'C', "Lock", "SX shared spin", "nsec", - "lockstat:::sx-spin", "arg2 != 0" }, - { 'C', "Lock", "Unknown event (type 16)", "units" }, - { 'C', "Lock", "Unknown event (type 17)", "units" }, - { 'C', "Lock", "Unknown event (type 18)", "units" }, - { 'C', "Lock", "Unknown event (type 19)", "units" }, + "lockstat:::sx-spin", "arg2 == 1" }, + { 'C', "Lock", "lockmgr writer blocked by writer", "nsec", + "lockstat:::lockmgr-block", "arg2 == 0 && arg3 == 1" }, + { 'C', "Lock", "lockmgr writer blocked by readers", "nsec", + "lockstat:::lockmgr-block", "arg2 == 0 && arg3 == 0 && arg4" }, + { 'C', "Lock", "lockmgr reader blocked by writer", "nsec", + "lockstat:::lockmgr-block", "arg2 == 1 && arg3 == 1" }, + { 'C', "Lock", "lockmgr reader blocked by write wanted", "nsec", + "lockstat:::lockmgr-block", "arg2 == 1 && arg3 == 0 && arg4" }, { 'C', "Lock", "Unknown event (type 20)", "units" }, { 'C', "Lock", "Unknown event (type 21)", "units" }, { 'C', "Lock", "Unknown event (type 22)", "units" }, Modified: head/share/man/man4/dtrace_lockstat.4 ============================================================================== --- head/share/man/man4/dtrace_lockstat.4 Wed Aug 21 23:24:40 2019 (r351360) +++ head/share/man/man4/dtrace_lockstat.4 Wed Aug 21 23:43:58 2019 (r351361) @@ -24,7 +24,7 @@ .\" .\" $FreeBSD$ .\" -.Dd March 2, 2018 +.Dd August 20, 2019 .Dt DTRACE_LOCKSTAT 4 .Os .Sh NAME @@ -50,6 +50,12 @@ .Fn lockstat:::sx-spin "struct sx *" "uint64_t" .Fn lockstat:::sx-upgrade "struct sx *" .Fn lockstat:::sx-downgrade "struct sx *" +.Fn lockstat:::lockmgr-acquire "struct lock *" "int" +.Fn lockstat:::lockmgr-release "struct lock *" "int" +.Fn lockstat:::lockmgr-disown "struct lock *" "int" +.Fn lockstat:::lockmgr-block "struct lock *" "uint64_t" "int" "int" "int" +.Fn lockstat:::lockmgr-upgrade "struct lock *" +.Fn lockstat:::lockmgr-downgrade "struct lock *" .Fn lockstat:::thread-spin "struct mtx *" "uint64" .Sh DESCRIPTION The DTrace @@ -62,6 +68,7 @@ The provider contains DTrace probes for inspecting kernel lock state transitions. Probes exist for the +.Xr lockmgr 9 , .Xr mutex 9 , .Xr rwlock 9 , and @@ -159,76 +166,50 @@ The second argument is if the lock is being acquired or released as a writer, and .Dv 1 if it is being acquired or released as a reader. -.Pp The -.Fn lockstat:::rw-block -probe fires when a thread removes itself from the CPU while -waiting to acquire a -.Xr rwlock 9 . -The -.Fn lockstat:::rw-spin -probe fires when a thread spins while waiting to acquire a -.Xr rwlock 9 . -Both probes take the same set of arguments. -The first argument is a pointer to the lock structure that describes -the lock. -The second argument is the length of time, in nanoseconds, -that the waiting thread was off the CPU or spinning for the lock. -The third argument is -.Dv 0 -if the thread is attempting to acquire the lock as a writer, and -.Dv 1 -if the thread is attempting to acquire the lock as a reader. -The fourth argument is -.Dv 0 -if the thread is waiting for a writer to release the lock, and -.Dv 1 -if the thread is waiting for a reader to release the lock. -The fifth argument is the number of readers that held the lock when -the thread first attempted to acquire the lock. -This argument will be -.Dv 0 -if the fourth argument is -.Dv 0 . -.Pp -The -.Fn lockstat:::rw-upgrade -probe fires when a thread successfully upgrades a held -.Xr rwlock 9 -read lock to a write lock. -The -.Fn lockstat:::rw-downgrade -probe fires when a thread downgrades a held -.Xr rwlock 9 -write lock to a read lock. -The only argument is a pointer to the structure which describes -the lock being acquired. -.Pp -The .Fn lockstat:::sx-acquire and -.Fn lockstat:::sx-release -probes fire when a +.Fn lockstat:::sx-release , +and +.Fn lockstat:::lockmgr-acquire +and +.Fn lockstat:::lockmgr-release +probes fire upon the corresponding events for .Xr sx 9 -is acquired or released, respectively. +and +.Xr lockmgr 9 +locks, respectively. +The +.Fn lockstat:::lockmgr-disown +probe fires when a +.Xr lockmgr 9 +exclusive lock is disowned. +In this state, the lock remains exclusively held, but may be +released by a different thread. +The +.Fn lockstat:::lockmgr-release +probe does not fire when releasing a disowned lock. The first argument is a pointer to the structure which describes -the lock being acquired. +the lock being disowned. The second argument is -.Dv 0 -if the shared lock is being acquired or released, and -.Dv 1 -if the exclusive lock is being acquired or released. +.Dv 0 , +for compatibility with +.Fn lockstat:::lockmgr-release . .Pp The -.Fn lockstat:::sx-block -probe fires when a thread takes itself off the CPU while -waiting to acquire a -.Xr sx 9 . +.Fn lockstat:::rw-block , +.Fn lockstat:::sx-block , +and +.Fn lockstat:::lockmgr-block +probes fire when a thread removes itself from the CPU while +waiting to acquire a lock of the corresponding type. The +.Fn lockstat:::rw-spin +and .Fn lockstat:::sx-spin -probe fires when a thread spins while waiting to acquire a -.Xr sx 9 . -Both probes take the same set of arguments. +probes fire when a thread spins while waiting to acquire a lock +of the corresponding type. +All probes take the same set of arguments. The first argument is a pointer to the lock structure that describes the lock. The second argument is the length of time, in nanoseconds, @@ -240,28 +221,40 @@ if the thread is attempting to acquire the lock as a w if the thread is attempting to acquire the lock as a reader. The fourth argument is .Dv 0 -if the thread is waiting for a writer to release the lock, and +if the thread is waiting for a reader to release the lock, and .Dv 1 -if the thread is waiting for a reader to release the lock. +if the thread is waiting for a writer to release the lock. The fifth argument is the number of readers that held the lock when the thread first attempted to acquire the lock. This argument will be .Dv 0 if the fourth argument is -.Dv 0 . +.Dv 1 . .Pp The +.Fn lockstat:::lockmgr-upgrade , +.Fn lockstat:::rw-upgrade , +and .Fn lockstat:::sx-upgrade -probe fires when a thread successfully upgrades a held +probes fire when a thread successfully upgrades a held +.Xr lockmgr 9 , +.Xr rwlock 9 , +or .Xr sx 9 -shared lock to an exclusive lock. +shared/reader lock to an exclusive/writer lock. The only argument is a pointer to the structure which describes the lock being acquired. The +.Fn lockstat:::lockmgr-downgrade , +.Fn lockstat:::rw-downgrade , +and .Fn lockstat:::sx-downgrade -probe fires when a thread downgrades a held +probes fire when a thread downgrades a held +.Xr lockmgr 9 , +.Xr rwlock 9 , +or .Xr sx 9 -exclusive lock to a shared lock. +exclusive/writer lock to a shared/reader lock. .Pp The .Fn lockstat:::thread-spin @@ -291,10 +284,11 @@ provider first appeared in .Fx 9 . .Sh AUTHORS This manual page was written by -.An George V. Neville-Neil Aq Mt gnn@FreeBSD.org . +.An George V. Neville-Neil Aq Mt gnn@FreeBSD.org +and +.An -nosplit +.An Mark Johnston Aq Mt markj@FreeBSD.org . .Sh BUGS Probes for -.Xr lockmgr 9 -and .Xr rmlock 9 locks have not yet been added. Modified: head/sys/kern/kern_lock.c ============================================================================== --- head/sys/kern/kern_lock.c Wed Aug 21 23:24:40 2019 (r351360) +++ head/sys/kern/kern_lock.c Wed Aug 21 23:43:58 2019 (r351361) @@ -40,6 +40,7 @@ __FBSDID("$FreeBSD$"); #include #include #include +#include #include #include #include @@ -201,8 +202,8 @@ lockmgr_note_shared_acquire(struct lock *lk, int conte uint64_t waittime, const char *file, int line, int flags) { - lock_profile_obtain_lock_success(&lk->lock_object, contested, waittime, - file, line); + LOCKSTAT_PROFILE_OBTAIN_RWLOCK_SUCCESS(lockmgr__acquire, lk, contested, + waittime, file, line, LOCKSTAT_READER); LOCK_LOG_LOCK("SLOCK", &lk->lock_object, 0, 0, file, line); WITNESS_LOCK(&lk->lock_object, LK_TRYWIT(flags), file, line); TD_LOCKS_INC(curthread); @@ -214,7 +215,7 @@ static void lockmgr_note_shared_release(struct lock *lk, const char *file, int line) { - lock_profile_release_lock(&lk->lock_object); + LOCKSTAT_PROFILE_RELEASE_RWLOCK(lockmgr__release, lk, LOCKSTAT_READER); WITNESS_UNLOCK(&lk->lock_object, 0, file, line); LOCK_LOG_LOCK("SUNLOCK", &lk->lock_object, 0, 0, file, line); TD_LOCKS_DEC(curthread); @@ -226,8 +227,8 @@ lockmgr_note_exclusive_acquire(struct lock *lk, int co uint64_t waittime, const char *file, int line, int flags) { - lock_profile_obtain_lock_success(&lk->lock_object, contested, waittime, - file, line); + LOCKSTAT_PROFILE_OBTAIN_RWLOCK_SUCCESS(lockmgr__acquire, lk, contested, + waittime, file, line, LOCKSTAT_WRITER); LOCK_LOG_LOCK("XLOCK", &lk->lock_object, 0, lk->lk_recurse, file, line); WITNESS_LOCK(&lk->lock_object, LOP_EXCLUSIVE | LK_TRYWIT(flags), file, line); @@ -239,7 +240,7 @@ static void lockmgr_note_exclusive_release(struct lock *lk, const char *file, int line) { - lock_profile_release_lock(&lk->lock_object); + LOCKSTAT_PROFILE_RELEASE_RWLOCK(lockmgr__release, lk, LOCKSTAT_WRITER); LOCK_LOG_LOCK("XUNLOCK", &lk->lock_object, 0, lk->lk_recurse, file, line); WITNESS_UNLOCK(&lk->lock_object, LOP_EXCLUSIVE, file, line); @@ -555,6 +556,9 @@ lockmgr_slock_hard(struct lock *lk, u_int flags, struc const char *iwmesg; int ipri, itimo; +#ifdef KDTRACE_HOOKS + uint64_t sleep_time = 0; +#endif #ifdef LOCK_PROFILING uint64_t waittime = 0; int contested = 0; @@ -645,8 +649,14 @@ retry_sleepq: * shared lock and the shared waiters flag is set, * we will sleep. */ +#ifdef KDTRACE_HOOKS + sleep_time -= lockstat_nsecs(&lk->lock_object); +#endif error = sleeplk(lk, flags, ilk, iwmesg, ipri, itimo, SQ_SHARED_QUEUE); +#ifdef KDTRACE_HOOKS + sleep_time += lockstat_nsecs(&lk->lock_object); +#endif flags &= ~LK_INTERLOCK; if (error) { LOCK_LOG3(lk, @@ -658,6 +668,12 @@ retry_sleepq: __func__, lk); } if (error == 0) { +#ifdef KDTRACE_HOOKS + if (sleep_time != 0) + LOCKSTAT_RECORD4(lockmgr__block, lk, sleep_time, + LOCKSTAT_READER, (x & LK_SHARE) == 0, + (x & LK_SHARE) == 0 ? 0 : LK_SHARERS(x)); +#endif #ifdef LOCK_PROFILING lockmgr_note_shared_acquire(lk, contested, waittime, file, line, flags); @@ -682,6 +698,9 @@ lockmgr_xlock_hard(struct lock *lk, u_int flags, struc const char *iwmesg; int ipri, itimo; +#ifdef KDTRACE_HOOKS + uint64_t sleep_time = 0; +#endif #ifdef LOCK_PROFILING uint64_t waittime = 0; int contested = 0; @@ -821,8 +840,14 @@ retry_sleepq: * exclusive lock and the exclusive waiters flag * is set, we will sleep. */ +#ifdef KDTRACE_HOOKS + sleep_time -= lockstat_nsecs(&lk->lock_object); +#endif error = sleeplk(lk, flags, ilk, iwmesg, ipri, itimo, SQ_EXCLUSIVE_QUEUE); +#ifdef KDTRACE_HOOKS + sleep_time += lockstat_nsecs(&lk->lock_object); +#endif flags &= ~LK_INTERLOCK; if (error) { LOCK_LOG3(lk, @@ -834,6 +859,12 @@ retry_sleepq: __func__, lk); } if (error == 0) { +#ifdef KDTRACE_HOOKS + if (sleep_time != 0) + LOCKSTAT_RECORD4(lockmgr__block, lk, sleep_time, + LOCKSTAT_WRITER, (x & LK_SHARE) == 0, + (x & LK_SHARE) == 0 ? 0 : LK_SHARERS(x)); +#endif #ifdef LOCK_PROFILING lockmgr_note_exclusive_acquire(lk, contested, waittime, file, line, flags); @@ -877,6 +908,7 @@ lockmgr_upgrade(struct lock *lk, u_int flags, struct l line); WITNESS_UPGRADE(&lk->lock_object, LOP_EXCLUSIVE | LK_TRYWIT(flags), file, line); + LOCKSTAT_RECORD0(lockmgr__upgrade, lk); TD_SLOCKS_DEC(curthread); goto out; } @@ -1024,7 +1056,8 @@ lockmgr_xunlock_hard(struct lock *lk, uintptr_t x, u_i goto out; } if (tid != LK_KERNPROC) - lock_profile_release_lock(&lk->lock_object); + LOCKSTAT_PROFILE_RELEASE_RWLOCK(lockmgr__release, lk, + LOCKSTAT_WRITER); if (x == tid && atomic_cmpset_rel_ptr(&lk->lk_lock, tid, LK_UNLOCKED)) goto out; @@ -1205,7 +1238,6 @@ __lockmgr_args(struct lock *lk, u_int flags, struct lo break; case LK_DOWNGRADE: _lockmgr_assert(lk, KA_XLOCKED, file, line); - LOCK_LOG_LOCK("XDOWNGRADE", &lk->lock_object, 0, 0, file, line); WITNESS_DOWNGRADE(&lk->lock_object, 0, file, line); /* @@ -1231,6 +1263,8 @@ __lockmgr_args(struct lock *lk, u_int flags, struct lo break; cpu_spinwait(); } + LOCK_LOG_LOCK("XDOWNGRADE", &lk->lock_object, 0, 0, file, line); + LOCKSTAT_RECORD0(lockmgr__downgrade, lk); break; case LK_RELEASE: _lockmgr_assert(lk, KA_LOCKED, file, line); @@ -1462,6 +1496,7 @@ _lockmgr_disown(struct lock *lk, const char *file, int if (LK_HOLDER(lk->lk_lock) != tid) return; lock_profile_release_lock(&lk->lock_object); + LOCKSTAT_RECORD1(lockmgr__disown, lk, LOCKSTAT_WRITER); LOCK_LOG_LOCK("XDISOWN", &lk->lock_object, 0, 0, file, line); WITNESS_UNLOCK(&lk->lock_object, LOP_EXCLUSIVE, file, line); TD_LOCKS_DEC(curthread); Modified: head/sys/kern/kern_lockstat.c ============================================================================== --- head/sys/kern/kern_lockstat.c Wed Aug 21 23:24:40 2019 (r351360) +++ head/sys/kern/kern_lockstat.c Wed Aug 21 23:43:58 2019 (r351361) @@ -62,6 +62,14 @@ SDT_PROBE_DEFINE2(lockstat, , , sx__spin, "struct sx * SDT_PROBE_DEFINE1(lockstat, , , sx__upgrade, "struct sx *"); SDT_PROBE_DEFINE1(lockstat, , , sx__downgrade, "struct sx *"); +SDT_PROBE_DEFINE2(lockstat, , , lockmgr__acquire, "struct lock *", "int"); +SDT_PROBE_DEFINE2(lockstat, , , lockmgr__release, "struct lock *", "int"); +SDT_PROBE_DEFINE2(lockstat, , , lockmgr__disown, "struct lock *", "int"); +SDT_PROBE_DEFINE5(lockstat, , , lockmgr__block, "struct lock *", "uint64_t", + "int", "int", "int"); +SDT_PROBE_DEFINE1(lockstat, , , lockmgr__upgrade, "struct lock *"); +SDT_PROBE_DEFINE1(lockstat, , , lockmgr__downgrade, "struct lock *"); + SDT_PROBE_DEFINE2(lockstat, , , thread__spin, "struct mtx *", "uint64_t"); volatile bool __read_frequently lockstat_enabled; Modified: head/sys/sys/lockstat.h ============================================================================== --- head/sys/sys/lockstat.h Wed Aug 21 23:24:40 2019 (r351360) +++ head/sys/sys/lockstat.h Wed Aug 21 23:43:58 2019 (r351361) @@ -65,6 +65,13 @@ SDT_PROBE_DECLARE(lockstat, , , sx__spin); SDT_PROBE_DECLARE(lockstat, , , sx__upgrade); SDT_PROBE_DECLARE(lockstat, , , sx__downgrade); +SDT_PROBE_DECLARE(lockstat, , , lockmgr__acquire); +SDT_PROBE_DECLARE(lockstat, , , lockmgr__release); +SDT_PROBE_DECLARE(lockstat, , , lockmgr__disown); +SDT_PROBE_DECLARE(lockstat, , , lockmgr__block); +SDT_PROBE_DECLARE(lockstat, , , lockmgr__upgrade); +SDT_PROBE_DECLARE(lockstat, , , lockmgr__downgrade); + SDT_PROBE_DECLARE(lockstat, , , thread__spin); #define LOCKSTAT_WRITER 0