xref: /freebsd/sys/kern/subr_lock.c (revision ba3c1f5972d7b90feb6e6da47905ff2757e0fe57)
1 /*-
2  * SPDX-License-Identifier: BSD-2-Clause
3  *
4  * Copyright (c) 2006 John Baldwin <jhb@FreeBSD.org>
5  *
6  * Redistribution and use in source and binary forms, with or without
7  * modification, are permitted provided that the following conditions
8  * are met:
9  * 1. Redistributions of source code must retain the above copyright
10  *    notice, this list of conditions and the following disclaimer.
11  * 2. Redistributions in binary form must reproduce the above copyright
12  *    notice, this list of conditions and the following disclaimer in the
13  *    documentation and/or other materials provided with the distribution.
14  *
15  * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
16  * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
17  * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
18  * ARE DISCLAIMED.  IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
19  * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
20  * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
21  * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
22  * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
23  * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
24  * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
25  * SUCH DAMAGE.
26  */
27 
28 /*
29  * This module holds the global variables and functions used to maintain
30  * lock_object structures.
31  */
32 
33 #include <sys/cdefs.h>
34 __FBSDID("$FreeBSD$");
35 
36 #include "opt_ddb.h"
37 #include "opt_mprof.h"
38 
39 #include <sys/param.h>
40 #include <sys/systm.h>
41 #include <sys/kernel.h>
42 #include <sys/ktr.h>
43 #include <sys/limits.h>
44 #include <sys/lock.h>
45 #include <sys/lock_profile.h>
46 #include <sys/malloc.h>
47 #include <sys/mutex.h>
48 #include <sys/pcpu.h>
49 #include <sys/proc.h>
50 #include <sys/sbuf.h>
51 #include <sys/sched.h>
52 #include <sys/smp.h>
53 #include <sys/sysctl.h>
54 
55 #ifdef DDB
56 #include <ddb/ddb.h>
57 #endif
58 
59 #include <machine/cpufunc.h>
60 
61 /*
62  * Uncomment to validate that spin argument to acquire/release routines matches
63  * the flag in the lock
64  */
65 //#define	LOCK_PROFILING_DEBUG_SPIN
66 
67 CTASSERT(LOCK_CLASS_MAX == 15);
68 
69 struct lock_class *lock_classes[LOCK_CLASS_MAX + 1] = {
70 	&lock_class_mtx_spin,
71 	&lock_class_mtx_sleep,
72 	&lock_class_sx,
73 	&lock_class_rm,
74 	&lock_class_rm_sleepable,
75 	&lock_class_rw,
76 	&lock_class_lockmgr,
77 };
78 
79 void
80 lock_init(struct lock_object *lock, struct lock_class *class, const char *name,
81     const char *type, int flags)
82 {
83 	int i;
84 
85 	/* Check for double-init and zero object. */
86 	KASSERT(flags & LO_NEW || !lock_initialized(lock),
87 	    ("lock \"%s\" %p already initialized", name, lock));
88 
89 	/* Look up lock class to find its index. */
90 	for (i = 0; i < LOCK_CLASS_MAX; i++)
91 		if (lock_classes[i] == class) {
92 			lock->lo_flags = i << LO_CLASSSHIFT;
93 			break;
94 		}
95 	KASSERT(i < LOCK_CLASS_MAX, ("unknown lock class %p", class));
96 
97 	/* Initialize the lock object. */
98 	lock->lo_name = name;
99 	lock->lo_flags |= flags | LO_INITIALIZED;
100 	LOCK_LOG_INIT(lock, 0);
101 	WITNESS_INIT(lock, (type != NULL) ? type : name);
102 }
103 
104 void
105 lock_destroy(struct lock_object *lock)
106 {
107 
108 	KASSERT(lock_initialized(lock), ("lock %p is not initialized", lock));
109 	WITNESS_DESTROY(lock);
110 	LOCK_LOG_DESTROY(lock, 0);
111 	lock->lo_flags &= ~LO_INITIALIZED;
112 }
113 
114 static SYSCTL_NODE(_debug, OID_AUTO, lock, CTLFLAG_RD | CTLFLAG_MPSAFE, NULL,
115     "lock debugging");
116 static SYSCTL_NODE(_debug_lock, OID_AUTO, delay,
117     CTLFLAG_RD | CTLFLAG_MPSAFE, NULL,
118     "lock delay");
119 
120 void
121 lock_delay(struct lock_delay_arg *la)
122 {
123 	struct lock_delay_config *lc = la->config;
124 	u_int i;
125 
126 	for (i = la->delay; i > 0; i--)
127 		cpu_spinwait();
128 	la->spin_cnt += la->delay;
129 
130 	la->delay <<= 1;
131 	if (__predict_false(la->delay > (u_int)lc->max))
132 		la->delay = lc->max;
133 }
134 
135 static u_int
136 lock_roundup_2(u_int val)
137 {
138 	u_int res;
139 
140 	for (res = 1; res <= val; res <<= 1)
141 		continue;
142 
143 	return (res);
144 }
145 
146 void
147 lock_delay_default_init(struct lock_delay_config *lc)
148 {
149 
150 	lc->base = 1;
151 	lc->max = min(lock_roundup_2(mp_ncpus) * 256, SHRT_MAX);
152 }
153 
154 struct lock_delay_config __read_frequently locks_delay;
155 u_short __read_frequently locks_delay_retries;
156 u_short __read_frequently locks_delay_loops;
157 
158 SYSCTL_U16(_debug_lock, OID_AUTO, delay_base, CTLFLAG_RW, &locks_delay.base,
159     0, "");
160 SYSCTL_U16(_debug_lock, OID_AUTO, delay_max, CTLFLAG_RW, &locks_delay.max,
161     0, "");
162 SYSCTL_U16(_debug_lock, OID_AUTO, delay_retries, CTLFLAG_RW, &locks_delay_retries,
163     0, "");
164 SYSCTL_U16(_debug_lock, OID_AUTO, delay_loops, CTLFLAG_RW, &locks_delay_loops,
165     0, "");
166 
167 static void
168 locks_delay_init(void *arg __unused)
169 {
170 
171 	lock_delay_default_init(&locks_delay);
172 	locks_delay_retries = 10;
173 	locks_delay_loops = max(10000, locks_delay.max);
174 }
175 LOCK_DELAY_SYSINIT(locks_delay_init);
176 
177 #ifdef DDB
178 DB_SHOW_COMMAND(lock, db_show_lock)
179 {
180 	struct lock_object *lock;
181 	struct lock_class *class;
182 
183 	if (!have_addr)
184 		return;
185 	lock = (struct lock_object *)addr;
186 	if (LO_CLASSINDEX(lock) > LOCK_CLASS_MAX) {
187 		db_printf("Unknown lock class: %d\n", LO_CLASSINDEX(lock));
188 		return;
189 	}
190 	class = LOCK_CLASS(lock);
191 	db_printf(" class: %s\n", class->lc_name);
192 	db_printf(" name: %s\n", lock->lo_name);
193 	class->lc_ddb_show(lock);
194 }
195 #endif
196 
197 #ifdef LOCK_PROFILING
198 
199 /*
200  * One object per-thread for each lock the thread owns.  Tracks individual
201  * lock instances.
202  */
203 struct lock_profile_object {
204 	LIST_ENTRY(lock_profile_object) lpo_link;
205 	struct lock_object *lpo_obj;
206 	const char	*lpo_file;
207 	int		lpo_line;
208 	uint16_t	lpo_ref;
209 	uint16_t	lpo_cnt;
210 	uint64_t	lpo_acqtime;
211 	uint64_t	lpo_waittime;
212 	u_int		lpo_contest_locking;
213 };
214 
215 /*
216  * One lock_prof for each (file, line, lock object) triple.
217  */
218 struct lock_prof {
219 	SLIST_ENTRY(lock_prof) link;
220 	struct lock_class *class;
221 	const char	*file;
222 	const char	*name;
223 	int		line;
224 	int		ticks;
225 	uintmax_t	cnt_wait_max;
226 	uintmax_t	cnt_max;
227 	uintmax_t	cnt_tot;
228 	uintmax_t	cnt_wait;
229 	uintmax_t	cnt_cur;
230 	uintmax_t	cnt_contest_locking;
231 };
232 
233 SLIST_HEAD(lphead, lock_prof);
234 
235 #define	LPROF_HASH_SIZE		4096
236 #define	LPROF_HASH_MASK		(LPROF_HASH_SIZE - 1)
237 #define	LPROF_CACHE_SIZE	4096
238 
239 /*
240  * Array of objects and profs for each type of object for each cpu.  Spinlocks
241  * are handled separately because a thread may be preempted and acquire a
242  * spinlock while in the lock profiling code of a non-spinlock.  In this way
243  * we only need a critical section to protect the per-cpu lists.
244  */
245 struct lock_prof_type {
246 	struct lphead		lpt_lpalloc;
247 	struct lpohead		lpt_lpoalloc;
248 	struct lphead		lpt_hash[LPROF_HASH_SIZE];
249 	struct lock_prof	lpt_prof[LPROF_CACHE_SIZE];
250 	struct lock_profile_object lpt_objs[LPROF_CACHE_SIZE];
251 };
252 
253 struct lock_prof_cpu {
254 	struct lock_prof_type	lpc_types[2]; /* One for spin one for other. */
255 };
256 
257 DPCPU_DEFINE_STATIC(struct lock_prof_cpu, lp);
258 #define	LP_CPU_SELF	(DPCPU_PTR(lp))
259 #define	LP_CPU(cpu)	(DPCPU_ID_PTR((cpu), lp))
260 
261 volatile int __read_mostly lock_prof_enable;
262 int __read_mostly lock_contested_only;
263 static volatile int lock_prof_resetting;
264 
265 #define LPROF_SBUF_SIZE		256
266 
267 static int lock_prof_rejected;
268 static int lock_prof_skipspin;
269 
270 #ifndef USE_CPU_NANOSECONDS
271 uint64_t
272 nanoseconds(void)
273 {
274 	struct bintime bt;
275 	uint64_t ns;
276 
277 	binuptime(&bt);
278 	/* From bintime2timespec */
279 	ns = bt.sec * (uint64_t)1000000000;
280 	ns += ((uint64_t)1000000000 * (uint32_t)(bt.frac >> 32)) >> 32;
281 	return (ns);
282 }
283 #endif
284 
285 static void
286 lock_prof_init_type(struct lock_prof_type *type)
287 {
288 	int i;
289 
290 	SLIST_INIT(&type->lpt_lpalloc);
291 	LIST_INIT(&type->lpt_lpoalloc);
292 	for (i = 0; i < LPROF_CACHE_SIZE; i++) {
293 		SLIST_INSERT_HEAD(&type->lpt_lpalloc, &type->lpt_prof[i],
294 		    link);
295 		LIST_INSERT_HEAD(&type->lpt_lpoalloc, &type->lpt_objs[i],
296 		    lpo_link);
297 	}
298 }
299 
300 static void
301 lock_prof_init(void *arg)
302 {
303 	int cpu;
304 
305 	CPU_FOREACH(cpu) {
306 		lock_prof_init_type(&LP_CPU(cpu)->lpc_types[0]);
307 		lock_prof_init_type(&LP_CPU(cpu)->lpc_types[1]);
308 	}
309 }
310 SYSINIT(lockprof, SI_SUB_SMP, SI_ORDER_ANY, lock_prof_init, NULL);
311 
312 static void
313 lock_prof_reset_wait(void)
314 {
315 
316 	/*
317 	 * Spin relinquishing our cpu so that quiesce_all_cpus may
318 	 * complete.
319 	 */
320 	while (lock_prof_resetting)
321 		sched_relinquish(curthread);
322 }
323 
324 static void
325 lock_prof_reset(void)
326 {
327 	struct lock_prof_cpu *lpc;
328 	int enabled, i, cpu;
329 
330 	/*
331 	 * We not only race with acquiring and releasing locks but also
332 	 * thread exit.  To be certain that threads exit without valid head
333 	 * pointers they must see resetting set before enabled is cleared.
334 	 * Otherwise a lock may not be removed from a per-thread list due
335 	 * to disabled being set but not wait for reset() to remove it below.
336 	 */
337 	atomic_store_rel_int(&lock_prof_resetting, 1);
338 	enabled = lock_prof_enable;
339 	lock_prof_enable = 0;
340 	/*
341 	 * This both publishes lock_prof_enable as disabled and makes sure
342 	 * everyone else reads it if they are not far enough. We wait for the
343 	 * rest down below.
344 	 */
345 	cpus_fence_seq_cst();
346 	quiesce_all_critical();
347 	/*
348 	 * Some objects may have migrated between CPUs.  Clear all links
349 	 * before we zero the structures.  Some items may still be linked
350 	 * into per-thread lists as well.
351 	 */
352 	CPU_FOREACH(cpu) {
353 		lpc = LP_CPU(cpu);
354 		for (i = 0; i < LPROF_CACHE_SIZE; i++) {
355 			LIST_REMOVE(&lpc->lpc_types[0].lpt_objs[i], lpo_link);
356 			LIST_REMOVE(&lpc->lpc_types[1].lpt_objs[i], lpo_link);
357 		}
358 	}
359 	CPU_FOREACH(cpu) {
360 		lpc = LP_CPU(cpu);
361 		bzero(lpc, sizeof(*lpc));
362 		lock_prof_init_type(&lpc->lpc_types[0]);
363 		lock_prof_init_type(&lpc->lpc_types[1]);
364 	}
365 	/*
366 	 * Paired with the fence from cpus_fence_seq_cst()
367 	 */
368 	atomic_store_rel_int(&lock_prof_resetting, 0);
369 	lock_prof_enable = enabled;
370 }
371 
372 static void
373 lock_prof_output(struct lock_prof *lp, struct sbuf *sb)
374 {
375 	const char *p;
376 
377 	for (p = lp->file; p != NULL && strncmp(p, "../", 3) == 0; p += 3);
378 	sbuf_printf(sb,
379 	    "%8ju %9ju %11ju %11ju %11ju %6ju %6ju %2ju %6ju %s:%d (%s:%s)\n",
380 	    lp->cnt_max / 1000, lp->cnt_wait_max / 1000, lp->cnt_tot / 1000,
381 	    lp->cnt_wait / 1000, lp->cnt_cur,
382 	    lp->cnt_cur == 0 ? (uintmax_t)0 :
383 	    lp->cnt_tot / (lp->cnt_cur * 1000),
384 	    lp->cnt_cur == 0 ? (uintmax_t)0 :
385 	    lp->cnt_wait / (lp->cnt_cur * 1000),
386 	    (uintmax_t)0, lp->cnt_contest_locking,
387 	    p, lp->line, lp->class->lc_name, lp->name);
388 }
389 
390 static void
391 lock_prof_sum(struct lock_prof *match, struct lock_prof *dst, int hash,
392     int spin, int t)
393 {
394 	struct lock_prof_type *type;
395 	struct lock_prof *l;
396 	int cpu;
397 
398 	dst->file = match->file;
399 	dst->line = match->line;
400 	dst->class = match->class;
401 	dst->name = match->name;
402 
403 	CPU_FOREACH(cpu) {
404 		type = &LP_CPU(cpu)->lpc_types[spin];
405 		SLIST_FOREACH(l, &type->lpt_hash[hash], link) {
406 			if (l->ticks == t)
407 				continue;
408 			if (l->file != match->file || l->line != match->line ||
409 			    l->name != match->name)
410 				continue;
411 			l->ticks = t;
412 			if (l->cnt_max > dst->cnt_max)
413 				dst->cnt_max = l->cnt_max;
414 			if (l->cnt_wait_max > dst->cnt_wait_max)
415 				dst->cnt_wait_max = l->cnt_wait_max;
416 			dst->cnt_tot += l->cnt_tot;
417 			dst->cnt_wait += l->cnt_wait;
418 			dst->cnt_cur += l->cnt_cur;
419 			dst->cnt_contest_locking += l->cnt_contest_locking;
420 		}
421 	}
422 }
423 
424 static void
425 lock_prof_type_stats(struct lock_prof_type *type, struct sbuf *sb, int spin,
426     int t)
427 {
428 	struct lock_prof *l;
429 	int i;
430 
431 	for (i = 0; i < LPROF_HASH_SIZE; ++i) {
432 		SLIST_FOREACH(l, &type->lpt_hash[i], link) {
433 			struct lock_prof lp = {};
434 
435 			if (l->ticks == t)
436 				continue;
437 			lock_prof_sum(l, &lp, i, spin, t);
438 			lock_prof_output(&lp, sb);
439 		}
440 	}
441 }
442 
443 static int
444 dump_lock_prof_stats(SYSCTL_HANDLER_ARGS)
445 {
446 	struct sbuf *sb;
447 	int error, cpu, t;
448 	int enabled;
449 
450 	error = sysctl_wire_old_buffer(req, 0);
451 	if (error != 0)
452 		return (error);
453 	sb = sbuf_new_for_sysctl(NULL, NULL, LPROF_SBUF_SIZE, req);
454 	sbuf_printf(sb, "\n%8s %9s %11s %11s %11s %6s %6s %2s %6s %s\n",
455 	    "max", "wait_max", "total", "wait_total", "count", "avg", "wait_avg", "cnt_hold", "cnt_lock", "name");
456 	enabled = lock_prof_enable;
457 	lock_prof_enable = 0;
458 	/*
459 	 * See the comment in lock_prof_reset
460 	 */
461 	cpus_fence_seq_cst();
462 	quiesce_all_critical();
463 	t = ticks;
464 	CPU_FOREACH(cpu) {
465 		lock_prof_type_stats(&LP_CPU(cpu)->lpc_types[0], sb, 0, t);
466 		lock_prof_type_stats(&LP_CPU(cpu)->lpc_types[1], sb, 1, t);
467 	}
468 	atomic_thread_fence_rel();
469 	lock_prof_enable = enabled;
470 
471 	error = sbuf_finish(sb);
472 	/* Output a trailing NUL. */
473 	if (error == 0)
474 		error = SYSCTL_OUT(req, "", 1);
475 	sbuf_delete(sb);
476 	return (error);
477 }
478 
479 static int
480 enable_lock_prof(SYSCTL_HANDLER_ARGS)
481 {
482 	int error, v;
483 
484 	v = lock_prof_enable;
485 	error = sysctl_handle_int(oidp, &v, v, req);
486 	if (error)
487 		return (error);
488 	if (req->newptr == NULL)
489 		return (error);
490 	if (v == lock_prof_enable)
491 		return (0);
492 	if (v == 1)
493 		lock_prof_reset();
494 	lock_prof_enable = !!v;
495 
496 	return (0);
497 }
498 
499 static int
500 reset_lock_prof_stats(SYSCTL_HANDLER_ARGS)
501 {
502 	int error, v;
503 
504 	v = 0;
505 	error = sysctl_handle_int(oidp, &v, 0, req);
506 	if (error)
507 		return (error);
508 	if (req->newptr == NULL)
509 		return (error);
510 	if (v == 0)
511 		return (0);
512 	lock_prof_reset();
513 
514 	return (0);
515 }
516 
517 static struct lock_prof *
518 lock_profile_lookup(struct lock_object *lo, int spin, const char *file,
519     int line)
520 {
521 	const char *unknown = "(unknown)";
522 	struct lock_prof_type *type;
523 	struct lock_prof *lp;
524 	struct lphead *head;
525 	const char *p;
526 	u_int hash;
527 
528 	p = file;
529 	if (p == NULL || *p == '\0')
530 		p = unknown;
531 	hash = (uintptr_t)lo->lo_name * 31 + (uintptr_t)p * 31 + line;
532 	hash &= LPROF_HASH_MASK;
533 	type = &LP_CPU_SELF->lpc_types[spin];
534 	head = &type->lpt_hash[hash];
535 	SLIST_FOREACH(lp, head, link) {
536 		if (lp->line == line && lp->file == p &&
537 		    lp->name == lo->lo_name)
538 			return (lp);
539 	}
540 	lp = SLIST_FIRST(&type->lpt_lpalloc);
541 	if (lp == NULL) {
542 		lock_prof_rejected++;
543 		return (lp);
544 	}
545 	SLIST_REMOVE_HEAD(&type->lpt_lpalloc, link);
546 	lp->file = p;
547 	lp->line = line;
548 	lp->class = LOCK_CLASS(lo);
549 	lp->name = lo->lo_name;
550 	SLIST_INSERT_HEAD(&type->lpt_hash[hash], lp, link);
551 	return (lp);
552 }
553 
554 static struct lock_profile_object *
555 lock_profile_object_lookup(struct lock_object *lo, int spin, const char *file,
556     int line)
557 {
558 	struct lock_profile_object *l;
559 	struct lock_prof_type *type;
560 	struct lpohead *head;
561 
562 	head = &curthread->td_lprof[spin];
563 	LIST_FOREACH(l, head, lpo_link)
564 		if (l->lpo_obj == lo && l->lpo_file == file &&
565 		    l->lpo_line == line)
566 			return (l);
567 	type = &LP_CPU_SELF->lpc_types[spin];
568 	l = LIST_FIRST(&type->lpt_lpoalloc);
569 	if (l == NULL) {
570 		lock_prof_rejected++;
571 		return (NULL);
572 	}
573 	LIST_REMOVE(l, lpo_link);
574 	l->lpo_obj = lo;
575 	l->lpo_file = file;
576 	l->lpo_line = line;
577 	l->lpo_cnt = 0;
578 	LIST_INSERT_HEAD(head, l, lpo_link);
579 
580 	return (l);
581 }
582 
583 void
584 lock_profile_obtain_lock_success(struct lock_object *lo, bool spin,
585     int contested, uint64_t waittime, const char *file, int line)
586 {
587 	struct lock_profile_object *l;
588 
589 #ifdef LOCK_PROFILING_DEBUG_SPIN
590 	bool is_spin = (LOCK_CLASS(lo)->lc_flags & LC_SPINLOCK);
591 	if ((spin && !is_spin) || (!spin && is_spin))
592 		printf("%s: lock %s spin mismatch (arg %d, flag %d)\n", __func__,
593 		    lo->lo_name, spin, is_spin);
594 #endif
595 
596 	/* don't reset the timer when/if recursing */
597 	if (!lock_prof_enable || (lo->lo_flags & LO_NOPROFILE))
598 		return;
599 	if (lock_contested_only && !contested)
600 		return;
601 	if (spin && lock_prof_skipspin == 1)
602 		return;
603 
604 	if (SCHEDULER_STOPPED())
605 		return;
606 
607 	critical_enter();
608 	/* Recheck enabled now that we're in a critical section. */
609 	if (lock_prof_enable == 0)
610 		goto out;
611 	l = lock_profile_object_lookup(lo, spin, file, line);
612 	if (l == NULL)
613 		goto out;
614 	l->lpo_cnt++;
615 	if (++l->lpo_ref > 1)
616 		goto out;
617 	l->lpo_contest_locking = contested;
618 	l->lpo_acqtime = nanoseconds();
619 	if (waittime && (l->lpo_acqtime > waittime))
620 		l->lpo_waittime = l->lpo_acqtime - waittime;
621 	else
622 		l->lpo_waittime = 0;
623 out:
624 	/*
625 	 * Paired with cpus_fence_seq_cst().
626 	 */
627 	atomic_thread_fence_rel();
628 	critical_exit();
629 }
630 
631 void
632 lock_profile_thread_exit(struct thread *td)
633 {
634 #ifdef INVARIANTS
635 	struct lock_profile_object *l;
636 
637 	MPASS(curthread->td_critnest == 0);
638 #endif
639 	/*
640 	 * If lock profiling was disabled we have to wait for reset to
641 	 * clear our pointers before we can exit safely.
642 	 */
643 	lock_prof_reset_wait();
644 #ifdef INVARIANTS
645 	LIST_FOREACH(l, &td->td_lprof[0], lpo_link)
646 		printf("thread still holds lock acquired at %s:%d\n",
647 		    l->lpo_file, l->lpo_line);
648 	LIST_FOREACH(l, &td->td_lprof[1], lpo_link)
649 		printf("thread still holds lock acquired at %s:%d\n",
650 		    l->lpo_file, l->lpo_line);
651 #endif
652 	MPASS(LIST_FIRST(&td->td_lprof[0]) == NULL);
653 	MPASS(LIST_FIRST(&td->td_lprof[1]) == NULL);
654 }
655 
656 void
657 lock_profile_release_lock(struct lock_object *lo, bool spin)
658 {
659 	struct lock_profile_object *l;
660 	struct lock_prof_type *type;
661 	struct lock_prof *lp;
662 	uint64_t curtime, holdtime;
663 	struct lpohead *head;
664 
665 #ifdef LOCK_PROFILING_DEBUG_SPIN
666 	bool is_spin = (LOCK_CLASS(lo)->lc_flags & LC_SPINLOCK);
667 	if ((spin && !is_spin) || (!spin && is_spin))
668 		printf("%s: lock %s spin mismatch (arg %d, flag %d)\n", __func__,
669 		    lo->lo_name, spin, is_spin);
670 #endif
671 
672 	if (lo->lo_flags & LO_NOPROFILE)
673 		return;
674 	head = &curthread->td_lprof[spin];
675 	if (LIST_FIRST(head) == NULL)
676 		return;
677 	if (SCHEDULER_STOPPED())
678 		return;
679 	critical_enter();
680 	/* Recheck enabled now that we're in a critical section. */
681 	if (lock_prof_enable == 0 && lock_prof_resetting == 1)
682 		goto out;
683 	/*
684 	 * If lock profiling is not enabled we still want to remove the
685 	 * lpo from our queue.
686 	 */
687 	LIST_FOREACH(l, head, lpo_link)
688 		if (l->lpo_obj == lo)
689 			break;
690 	if (l == NULL)
691 		goto out;
692 	if (--l->lpo_ref > 0)
693 		goto out;
694 	lp = lock_profile_lookup(lo, spin, l->lpo_file, l->lpo_line);
695 	if (lp == NULL)
696 		goto release;
697 	curtime = nanoseconds();
698 	if (curtime < l->lpo_acqtime)
699 		goto release;
700 	holdtime = curtime - l->lpo_acqtime;
701 
702 	/*
703 	 * Record if the lock has been held longer now than ever
704 	 * before.
705 	 */
706 	if (holdtime > lp->cnt_max)
707 		lp->cnt_max = holdtime;
708 	if (l->lpo_waittime > lp->cnt_wait_max)
709 		lp->cnt_wait_max = l->lpo_waittime;
710 	lp->cnt_tot += holdtime;
711 	lp->cnt_wait += l->lpo_waittime;
712 	lp->cnt_contest_locking += l->lpo_contest_locking;
713 	lp->cnt_cur += l->lpo_cnt;
714 release:
715 	LIST_REMOVE(l, lpo_link);
716 	type = &LP_CPU_SELF->lpc_types[spin];
717 	LIST_INSERT_HEAD(&type->lpt_lpoalloc, l, lpo_link);
718 out:
719 	/*
720 	 * Paired with cpus_fence_seq_cst().
721 	 */
722 	atomic_thread_fence_rel();
723 	critical_exit();
724 }
725 
726 static SYSCTL_NODE(_debug_lock, OID_AUTO, prof,
727     CTLFLAG_RD | CTLFLAG_MPSAFE, NULL,
728     "lock profiling");
729 SYSCTL_INT(_debug_lock_prof, OID_AUTO, skipspin, CTLFLAG_RW,
730     &lock_prof_skipspin, 0, "Skip profiling on spinlocks.");
731 SYSCTL_INT(_debug_lock_prof, OID_AUTO, rejected, CTLFLAG_RD,
732     &lock_prof_rejected, 0, "Number of rejected profiling records");
733 SYSCTL_INT(_debug_lock_prof, OID_AUTO, contested_only, CTLFLAG_RW,
734     &lock_contested_only, 0, "Only profile contested acquires");
735 SYSCTL_PROC(_debug_lock_prof, OID_AUTO, stats,
736     CTLTYPE_STRING | CTLFLAG_RD | CTLFLAG_MPSAFE, NULL, 0,
737     dump_lock_prof_stats, "A",
738     "Lock profiling statistics");
739 SYSCTL_PROC(_debug_lock_prof, OID_AUTO, reset,
740     CTLTYPE_INT | CTLFLAG_RW | CTLFLAG_NEEDGIANT, NULL, 0,
741     reset_lock_prof_stats, "I",
742     "Reset lock profiling statistics");
743 SYSCTL_PROC(_debug_lock_prof, OID_AUTO, enable,
744     CTLTYPE_INT | CTLFLAG_RW | CTLFLAG_MPSAFE, NULL, 0,
745     enable_lock_prof, "I",
746     "Enable lock profiling");
747 
748 #endif
749