svn commit: r291059 - in head: share/man/man4 sys/kern
Mark Johnston
markj at FreeBSD.org
Thu Nov 19 05:57:01 UTC 2015
Author: markj
Date: Thu Nov 19 05:56:59 2015
New Revision: 291059
URL: https://svnweb.freebsd.org/changeset/base/291059
Log:
Add support for a configurable output channel to witness(4).
This is useful in environments where system configuration is performed by
automated interaction with the system console, since unexpected witness
output makes such automation difficult. With this change, the new
debug.witness.output_channel sysctl allows one to specify that witness
output is to be printed to the kernel log (using log(9)) rather than the
console.
Reviewed by: cem, jhb
MFC after: 2 weeks
Relnotes: yes
Sponsored by: EMC / Isilon Storage Division
Differential Revision: https://reviews.freebsd.org/D4183
Modified:
head/share/man/man4/witness.4
head/sys/kern/subr_stack.c
head/sys/kern/subr_witness.c
Modified: head/share/man/man4/witness.4
==============================================================================
--- head/share/man/man4/witness.4 Thu Nov 19 05:50:22 2015 (r291058)
+++ head/share/man/man4/witness.4 Thu Nov 19 05:56:59 2015 (r291059)
@@ -24,7 +24,7 @@
.\"
.\" $FreeBSD$
.\"
-.Dd March 24, 2015
+.Dd November 18, 2015
.Dt WITNESS 4
.Os
.Sh NAME
@@ -47,7 +47,8 @@ Each time a lock is acquired,
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 @@ The sysctl
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
Modified: head/sys/kern/subr_stack.c
==============================================================================
--- head/sys/kern/subr_stack.c Thu Nov 19 05:50:22 2015 (r291058)
+++ head/sys/kern/subr_stack.c Thu Nov 19 05:56:59 2015 (r291059)
@@ -141,7 +141,7 @@ stack_print_ddb(const struct stack *st)
}
}
-#ifdef DDB
+#if defined(DDB) || defined(WITNESS)
void
stack_print_short_ddb(const struct stack *st)
{
@@ -182,7 +182,7 @@ stack_sbuf_print(struct sbuf *sb, const
}
}
-#ifdef DDB
+#if defined(DDB) || defined(WITNESS)
void
stack_sbuf_print_ddb(struct sbuf *sb, const struct stack *st)
{
Modified: head/sys/kern/subr_witness.c
==============================================================================
--- head/sys/kern/subr_witness.c Thu Nov 19 05:50:22 2015 (r291058)
+++ head/sys/kern/subr_witness.c Thu Nov 19 05:56:59 2015 (r291059)
@@ -106,6 +106,7 @@ __FBSDID("$FreeBSD$");
#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 @@ witness_lock_order_key_equal(const struc
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 void itismychild(struct witness *
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_display_list(int
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 @@ static struct witness_lock_order_data *w
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 = 1;
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 @@ SYSCTL_INT(_debug_witness, OID_AUTO, wit
&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 @@ witness_checkorder(struct lock_object *l
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 @@ witness_checkorder(struct lock_object *l
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 @@ witness_checkorder(struct lock_object *l
*/
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 @@ witness_checkorder(struct lock_object *l
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 @@ found:
/* 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 @@ found:
}
/* 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 @@ witness_thread_exit(struct thread *td)
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 @@ witness_thread_exit(struct thread *td)
* 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 @@ witness_warn(int flags, struct lock_obje
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 @@ witness_warn(int flags, struct lock_obje
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 @@ witness_list_lock(struct lock_instance *
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)
@@ -2650,6 +2692,42 @@ restart:
}
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 +2989,38 @@ witness_increment_graph_generation(void)
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
+}
More information about the svn-src-head
mailing list