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 +} _______________________________________________ svn-src-all@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/svn-src-all To unsubscribe, send any mail to "svn-src-all-unsubscr...@freebsd.org"
