Page MenuHomeFreeBSD
Files F131902425

D4183.id10248.diff
No OneTemporary
Actions

D4183.id10248.diff
View Options

Index: share/man/man4/witness.4
===================================================================
--- share/man/man4/witness.4
+++ share/man/man4/witness.4
@@ -24,7 +24,7 @@
.\"
.\" $FreeBSD$
.\"
-.Dd March 24, 2015
+.Dd November 11, 2015
.Dt WITNESS 4
.Os
.Sh NAME
@@ -47,7 +47,8 @@
uses these two lists to verify that a lock is not being acquired in the
wrong order.
If a lock order violation is detected, then a message is output to the
-kernel console detailing the locks involved and the locations in question.
+kernel console or log detailing the locks involved and the locations in
+question.
Witness can also be configured to drop into the kernel debugger when an order
violation occurs.
.Pp
@@ -125,6 +126,21 @@
can be set via
.Xr loader 8 .
.Pp
+The sysctl
+.Va debug.witness.output_channel
+specifies the output channel used to display warnings emitted by
+.Nm .
+The possible values are
+.Ql console ,
+indicating that warnings are to be printed to the system console,
+.Ql log ,
+indicating that warnings are to be logged via
+.Xr log 9 ,
+and
+.Ql none .
+This sysctl can be set via
+.Xr loader 8 .
+.Pp
The
.Nm
code also provides three extra
Index: share/man/man9/printf.9
===================================================================
--- share/man/man9/printf.9
+++ share/man/man9/printf.9
@@ -26,7 +26,7 @@
.\"
.\" $FreeBSD$
.\"
-.Dd September 8, 2006
+.Dd November 9, 2015
.Dt PRINTF 9
.Os
.Sh NAME
@@ -41,9 +41,13 @@
.Fn tprintf "struct proc *p" "int pri" "const char *fmt" ...
.Ft int
.Fn uprintf "const char *fmt" ...
+.Ft int
+.Fn vprintf "const char *fmt" "va_list ap"
.In sys/syslog.h
.Ft void
.Fn log "int pri" "const char *fmt" ...
+.Ft void
+.Fn vlog "int pri" "const char *fmt" "va_list ap"
.Sh DESCRIPTION
The
.Xr printf 9
Index: sys/kern/subr_prf.c
===================================================================
--- sys/kern/subr_prf.c
+++ sys/kern/subr_prf.c
@@ -302,9 +302,15 @@
va_list ap;
va_start(ap, fmt);
- (void)_vprintf(level, log_open ? TOLOG : TOCONS | TOLOG, fmt, ap);
+ vlog(level, fmt, ap);
va_end(ap);
+}
+
+void
+vlog(int level, const char *fmt, va_list ap)
+{
+ (void)_vprintf(level, log_open ? TOLOG : TOCONS | TOLOG, fmt, ap);
msgbuftrigger = 1;
}
Index: sys/kern/subr_stack.c
===================================================================
--- sys/kern/subr_stack.c
+++ sys/kern/subr_stack.c
@@ -141,7 +141,7 @@
}
}
-#ifdef DDB
+#if defined(DDB) || defined(WITNESS)
void
stack_print_short_ddb(const struct stack *st)
{
@@ -182,7 +182,7 @@
}
}
-#ifdef DDB
+#if defined(DDB) || defined(WITNESS)
void
stack_sbuf_print_ddb(struct sbuf *sb, const struct stack *st)
{
Index: sys/kern/subr_witness.c
===================================================================
--- sys/kern/subr_witness.c
+++ sys/kern/subr_witness.c
@@ -106,6 +106,7 @@
#include <sys/sched.h>
#include <sys/stack.h>
#include <sys/sysctl.h>
+#include <sys/syslog.h>
#include <sys/systm.h>
#ifdef DDB
@@ -314,9 +315,6 @@
static int _isitmyx(struct witness *w1, struct witness *w2, int rmask,
const char *fname);
-#ifdef KDB
-static void _witness_debugger(int cond, const char *msg);
-#endif
static void adopt(struct witness *parent, struct witness *child);
#ifdef BLESSING
static int blessed(struct witness *, struct witness *);
@@ -332,6 +330,7 @@
static int sysctl_debug_witness_badstacks(SYSCTL_HANDLER_ARGS);
static int sysctl_debug_witness_watch(SYSCTL_HANDLER_ARGS);
static int sysctl_debug_witness_fullgraph(SYSCTL_HANDLER_ARGS);
+static int sysctl_debug_witness_channel(SYSCTL_HANDLER_ARGS);
static void witness_add_fullgraph(struct sbuf *sb, struct witness *parent);
#ifdef DDB
static void witness_ddb_compute_levels(void);
@@ -343,6 +342,7 @@
static void witness_ddb_level_descendants(struct witness *parent, int l);
static void witness_ddb_list(struct thread *td);
#endif
+static void witness_debugger(int cond, const char *msg);
static void witness_free(struct witness *m);
static struct witness *witness_get(void);
static uint32_t witness_hash_djb2(const uint8_t *key, uint32_t size);
@@ -361,14 +361,10 @@
struct witness *child);
static void witness_list_lock(struct lock_instance *instance,
int (*prnt)(const char *fmt, ...));
+static int witness_output(const char *fmt, ...) __printflike(1, 2);
+static int witness_voutput(const char *fmt, va_list ap) __printflike(1, 0);
static void witness_setflag(struct lock_object *lock, int flag, int set);
-#ifdef KDB
-#define witness_debugger(c) _witness_debugger(c, __func__)
-#else
-#define witness_debugger(c)
-#endif
-
static SYSCTL_NODE(_debug, OID_AUTO, witness, CTLFLAG_RW, NULL,
"Witness Locking");
@@ -396,16 +392,18 @@
int witness_kdb = 0;
#endif
SYSCTL_INT(_debug_witness, OID_AUTO, kdb, CTLFLAG_RWTUN, &witness_kdb, 0, "");
+#endif /* KDB */
+#if defined(DDB) || defined(KDB)
/*
- * When KDB is enabled and witness_trace is 1, it will cause the system
+ * When DDB or KDB is enabled and witness_trace is 1, it will cause the system
* to print a stack trace:
* - a lock hierarchy violation occurs
* - locks are held when going to sleep.
*/
int witness_trace = 1;
SYSCTL_INT(_debug_witness, OID_AUTO, trace, CTLFLAG_RWTUN, &witness_trace, 0, "");
-#endif /* KDB */
+#endif /* DDB || KDB */
#ifdef WITNESS_SKIPSPIN
int witness_skipspin = 1;
@@ -421,6 +419,20 @@
&witness_count, 0, "");
/*
+ * Output channel for witness messages. By default we print to the console.
+ */
+enum witness_channel {
+ WITNESS_CONSOLE,
+ WITNESS_LOG,
+ WITNESS_NONE,
+};
+
+static enum witness_channel witness_channel = WITNESS_CONSOLE;
+SYSCTL_PROC(_debug_witness, OID_AUTO, output_channel, CTLTYPE_STRING |
+ CTLFLAG_RWTUN, NULL, 0, sysctl_debug_witness_channel, "A",
+ "Output channel for warnings");
+
+/*
* Call this to print out the relations between locks.
*/
SYSCTL_PROC(_debug_witness, OID_AUTO, fullgraph, CTLTYPE_STRING | CTLFLAG_RD,
@@ -1117,19 +1129,19 @@
if (lock1 != NULL) {
if ((lock1->li_flags & LI_EXCLUSIVE) != 0 &&
(flags & LOP_EXCLUSIVE) == 0) {
- printf("shared lock of (%s) %s @ %s:%d\n",
+ witness_output("shared lock of (%s) %s @ %s:%d\n",
class->lc_name, lock->lo_name,
fixup_filename(file), line);
- printf("while exclusively locked from %s:%d\n",
+ witness_output("while exclusively locked from %s:%d\n",
fixup_filename(lock1->li_file), lock1->li_line);
kassert_panic("excl->share");
}
if ((lock1->li_flags & LI_EXCLUSIVE) == 0 &&
(flags & LOP_EXCLUSIVE) != 0) {
- printf("exclusive lock of (%s) %s @ %s:%d\n",
+ witness_output("exclusive lock of (%s) %s @ %s:%d\n",
class->lc_name, lock->lo_name,
fixup_filename(file), line);
- printf("while share locked from %s:%d\n",
+ witness_output("while share locked from %s:%d\n",
fixup_filename(lock1->li_file), lock1->li_line);
kassert_panic("share->excl");
}
@@ -1199,14 +1211,14 @@
w_rmatrix[i][i] |= WITNESS_REVERSAL;
w->w_reversed = 1;
mtx_unlock_spin(&w_mtx);
- printf(
+ witness_output(
"acquiring duplicate lock of same type: \"%s\"\n",
w->w_name);
- printf(" 1st %s @ %s:%d\n", plock->li_lock->lo_name,
+ witness_output(" 1st %s @ %s:%d\n", plock->li_lock->lo_name,
fixup_filename(plock->li_file), plock->li_line);
- printf(" 2nd %s @ %s:%d\n", lock->lo_name,
+ witness_output(" 2nd %s @ %s:%d\n", lock->lo_name,
fixup_filename(file), line);
- witness_debugger(1);
+ witness_debugger(1, __func__);
} else
mtx_unlock_spin(&w_mtx);
return;
@@ -1328,14 +1340,14 @@
*/
if (((lock->lo_flags & LO_SLEEPABLE) != 0 &&
(lock1->li_lock->lo_flags & LO_SLEEPABLE) == 0))
- printf(
+ witness_output(
"lock order reversal: (sleepable after non-sleepable)\n");
else if ((lock1->li_lock->lo_flags & LO_SLEEPABLE) == 0
&& lock == &Giant.lock_object)
- printf(
+ witness_output(
"lock order reversal: (Giant after non-sleepable)\n");
else
- printf("lock order reversal:\n");
+ witness_output("lock order reversal:\n");
/*
* Try to locate an earlier lock with
@@ -1354,28 +1366,28 @@
i--;
} while (i >= 0);
if (i < 0) {
- printf(" 1st %p %s (%s) @ %s:%d\n",
+ witness_output(" 1st %p %s (%s) @ %s:%d\n",
lock1->li_lock, lock1->li_lock->lo_name,
w1->w_name, fixup_filename(lock1->li_file),
lock1->li_line);
- printf(" 2nd %p %s (%s) @ %s:%d\n", lock,
+ witness_output(" 2nd %p %s (%s) @ %s:%d\n", lock,
lock->lo_name, w->w_name,
fixup_filename(file), line);
} else {
- printf(" 1st %p %s (%s) @ %s:%d\n",
+ witness_output(" 1st %p %s (%s) @ %s:%d\n",
lock2->li_lock, lock2->li_lock->lo_name,
lock2->li_lock->lo_witness->w_name,
fixup_filename(lock2->li_file),
lock2->li_line);
- printf(" 2nd %p %s (%s) @ %s:%d\n",
+ witness_output(" 2nd %p %s (%s) @ %s:%d\n",
lock1->li_lock, lock1->li_lock->lo_name,
w1->w_name, fixup_filename(lock1->li_file),
lock1->li_line);
- printf(" 3rd %p %s (%s) @ %s:%d\n", lock,
+ witness_output(" 3rd %p %s (%s) @ %s:%d\n", lock,
lock->lo_name, w->w_name,
fixup_filename(file), line);
}
- witness_debugger(1);
+ witness_debugger(1, __func__);
return;
}
}
@@ -1593,17 +1605,17 @@
/* First, check for shared/exclusive mismatches. */
if ((instance->li_flags & LI_EXCLUSIVE) != 0 && witness_watch > 0 &&
(flags & LOP_EXCLUSIVE) == 0) {
- printf("shared unlock of (%s) %s @ %s:%d\n", class->lc_name,
- lock->lo_name, fixup_filename(file), line);
- printf("while exclusively locked from %s:%d\n",
+ witness_output("shared unlock of (%s) %s @ %s:%d\n",
+ class->lc_name, lock->lo_name, fixup_filename(file), line);
+ witness_output("while exclusively locked from %s:%d\n",
fixup_filename(instance->li_file), instance->li_line);
kassert_panic("excl->ushare");
}
if ((instance->li_flags & LI_EXCLUSIVE) == 0 && witness_watch > 0 &&
(flags & LOP_EXCLUSIVE) != 0) {
- printf("exclusive unlock of (%s) %s @ %s:%d\n", class->lc_name,
- lock->lo_name, fixup_filename(file), line);
- printf("while share locked from %s:%d\n",
+ witness_output("exclusive unlock of (%s) %s @ %s:%d\n",
+ class->lc_name, lock->lo_name, fixup_filename(file), line);
+ witness_output("while share locked from %s:%d\n",
fixup_filename(instance->li_file),
instance->li_line);
kassert_panic("share->uexcl");
@@ -1618,8 +1630,8 @@
}
/* The lock is now being dropped, check for NORELEASE flag */
if ((instance->li_flags & LI_NORELEASE) != 0 && witness_watch > 0) {
- printf("forbidden unlock of (%s) %s @ %s:%d\n", class->lc_name,
- lock->lo_name, fixup_filename(file), line);
+ witness_output("forbidden unlock of (%s) %s @ %s:%d\n",
+ class->lc_name, lock->lo_name, fixup_filename(file), line);
kassert_panic("lock marked norelease");
}
@@ -1669,10 +1681,11 @@
for (n = 0; lle != NULL; lle = lle->ll_next)
for (i = lle->ll_count - 1; i >= 0; i--) {
if (n == 0)
- printf("Thread %p exiting with the following locks held:\n",
- td);
+ witness_output(
+ "Thread %p exiting with the following locks held:\n", td);
n++;
- witness_list_lock(&lle->ll_children[i], printf);
+ witness_list_lock(&lle->ll_children[i],
+ witness_output);
}
kassert_panic(
@@ -1685,7 +1698,7 @@
* Warn if any locks other than 'lock' are held. Flags can be passed in to
* exempt Giant and sleepable locks from the checks as well. If any
* non-exempt locks are held, then a supplied message is printed to the
- * console along with a list of the offending locks. If indicated in the
+ * output channel along with a list of the offending locks. If indicated in the
* flags then a failure results in a panic as well.
*/
int
@@ -1714,15 +1727,15 @@
continue;
if (n == 0) {
va_start(ap, fmt);
- vprintf(fmt, ap);
+ witness_voutput(fmt, ap);
va_end(ap);
- printf(" with the following");
- if (flags & WARN_SLEEPOK)
- printf(" non-sleepable");
- printf(" locks held:\n");
+ witness_output(
+ " with the following %slocks held:\n",
+ (flags & WARN_SLEEPOK) != 0 ?
+ "non-sleepable " : "");
}
n++;
- witness_list_lock(lock1, printf);
+ witness_list_lock(lock1, witness_output);
}
/*
@@ -1747,19 +1760,17 @@
return (0);
va_start(ap, fmt);
- vprintf(fmt, ap);
+ witness_voutput(fmt, ap);
va_end(ap);
- printf(" with the following");
- if (flags & WARN_SLEEPOK)
- printf(" non-sleepable");
- printf(" locks held:\n");
- n += witness_list_locks(&lock_list, printf);
+ witness_output(" with the following %slocks held:\n",
+ (flags & WARN_SLEEPOK) != 0 ? "non-sleepable " : "");
+ n += witness_list_locks(&lock_list, witness_output);
} else
sched_unpin();
if (flags & WARN_PANIC && n)
kassert_panic("%s", __func__);
else
- witness_debugger(n);
+ witness_debugger(n, __func__);
return (n);
}
@@ -2167,6 +2178,37 @@
fixup_filename(instance->li_file), instance->li_line);
}
+static int
+witness_output(const char *fmt, ...)
+{
+ va_list ap;
+ int ret;
+
+ va_start(ap, fmt);
+ ret = witness_voutput(fmt, ap);
+ va_end(ap);
+ return (ret);
+}
+
+static int
+witness_voutput(const char *fmt, va_list ap)
+{
+ int ret;
+
+ ret = 0;
+ switch (witness_channel) {
+ case WITNESS_CONSOLE:
+ ret = vprintf(fmt, ap);
+ break;
+ case WITNESS_LOG:
+ vlog(LOG_NOTICE, fmt, ap);
+ break;
+ case WITNESS_NONE:
+ break;
+ }
+ return (ret);
+}
+
#ifdef DDB
static int
witness_thread_has_locks(struct thread *td)
@@ -2598,12 +2640,6 @@
"\nLock order reversal between \"%s\"(%s) and \"%s\"(%s)!\n",
tmp_w1->w_name, tmp_w1->w_class->lc_name,
tmp_w2->w_name, tmp_w2->w_class->lc_name);
-#if 0
- sbuf_printf(sb,
- "w_rmatrix[%s][%s] == %x, w_rmatrix[%s][%s] == %x\n",
- tmp_w1->name, tmp_w2->w_name, w_rmatrix1,
- tmp_w2->name, tmp_w1->w_name, w_rmatrix2);
-#endif
if (data1) {
sbuf_printf(sb,
"Lock order \"%s\"(%s) -> \"%s\"(%s) first seen at:\n",
@@ -2650,6 +2686,42 @@
}
static int
+sysctl_debug_witness_channel(SYSCTL_HANDLER_ARGS)
+{
+ static const struct {
+ enum witness_channel channel;
+ const char *name;
+ } channels[] = {
+ { WITNESS_CONSOLE, "console" },
+ { WITNESS_LOG, "log" },
+ { WITNESS_NONE, "none" },
+ };
+ char buf[16];
+ u_int i;
+ int error;
+
+ buf[0] = '\0';
+ for (i = 0; i < nitems(channels); i++)
+ if (witness_channel == channels[i].channel) {
+ snprintf(buf, sizeof(buf), "%s", channels[i].name);
+ break;
+ }
+
+ error = sysctl_handle_string(oidp, buf, sizeof(buf), req);
+ if (error != 0 || req->newptr == NULL)
+ return (error);
+
+ error = EINVAL;
+ for (i = 0; i < nitems(channels); i++)
+ if (strcmp(channels[i].name, buf) == 0) {
+ witness_channel = channels[i].channel;
+ error = 0;
+ break;
+ }
+ return (error);
+}
+
+static int
sysctl_debug_witness_fullgraph(SYSCTL_HANDLER_ARGS)
{
struct witness *w;
@@ -2911,14 +2983,38 @@
w_generation++;
}
-#ifdef KDB
+static int
+witness_output_drain(void *arg __unused, const char *data, int len)
+{
+
+ witness_output("%s", data);
+ return (len);
+}
+
static void
-_witness_debugger(int cond, const char *msg)
+witness_debugger(int cond, const char *msg)
{
+ char buf[32];
+ struct sbuf sb;
+ struct stack st;
- if (witness_trace && cond)
- kdb_backtrace();
- if (witness_kdb && cond)
+ if (!cond)
+ return;
+
+ if (witness_trace) {
+ sbuf_new(&sb, buf, sizeof(buf), SBUF_FIXEDLEN);
+ sbuf_set_drain(&sb, witness_output_drain, NULL);
+
+ stack_zero(&st);
+ stack_save(&st);
+ witness_output("stack backtrace:\n");
+ stack_sbuf_print_ddb(&sb, &st);
+
+ sbuf_finish(&sb);
+ }
+
+#ifdef KDB
+ if (witness_kdb)
kdb_enter(KDB_WHY_WITNESS, msg);
-}
#endif
+}
Index: sys/sys/systm.h
===================================================================
--- sys/sys/systm.h
+++ sys/sys/systm.h
@@ -207,6 +207,7 @@
__va_list) __printflike(1, 0);
void log(int, const char *, ...) __printflike(2, 3);
void log_console(struct uio *);
+void vlog(int, const char *, __va_list) __printflike(2, 0);
int asprintf(char **ret, struct malloc_type *mtp, const char *format,
...) __printflike(3, 4);
int printf(const char *, ...) __printflike(1, 2);

File Metadata

Mime Type
text/plain
Expires
Mon, Oct 13, 2:29 AM (12 h, 23 m)
Storage Engine
blob
Storage Format
Raw Data
Storage Handle
23652410
Default Alt Text
D4183.id10248.diff (16 KB)

Event Timeline