From owner-freebsd-arch@FreeBSD.ORG Fri Dec 7 18:25:57 2012 Return-Path: Delivered-To: freebsd-arch@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id BB71F578; Fri, 7 Dec 2012 18:25:57 +0000 (UTC) (envelope-from bright@mu.org) Received: from elvis.mu.org (elvis.mu.org [192.203.228.196]) by mx1.freebsd.org (Postfix) with ESMTP id 979548FC15; Fri, 7 Dec 2012 18:25:54 +0000 (UTC) Received: from Alfreds-MacBook-Pro-6.local (c-67-180-208-218.hsd1.ca.comcast.net [67.180.208.218]) by elvis.mu.org (Postfix) with ESMTPSA id 6BDA81A3C78; Fri, 7 Dec 2012 10:25:54 -0800 (PST) Message-ID: <50C234B1.6090803@mu.org> Date: Fri, 07 Dec 2012 10:25:53 -0800 From: Alfred Perlstein User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.7; rv:17.0) Gecko/17.0 Thunderbird/17.0 MIME-Version: 1.0 To: mdf@FreeBSD.org Subject: Re: svn commit: r243980 - in head/sys: kern sys References: <201212070825.qB78P9rY055786@svn.freebsd.org> In-Reply-To: Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: Adrian Chadd , Alfred Perlstein , freebsd-arch@freebsd.org X-BeenThere: freebsd-arch@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Discussion related to FreeBSD architecture List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 07 Dec 2012 18:25:57 -0000 On 12/7/12 7:12 AM, mdf@FreeBSD.org wrote: > On Fri, Dec 7, 2012 at 6:25 AM, Adrian Chadd wrote: >> Ok, so can we now please split 'panic during debugging but we do >> handle the case' and 'panic during live runs as it really does mean >> we're hosed' assert checks, so coders can choose which is appropriate? >> >> Or does that now exist? > This should already exist, as KASSERT was only for INVARIANTS and > presumably no one runs that code in production. > > At $work we have an ugly macro but a flexible system for this -- > checks are grouped into areas, and each one has a set of sysctl nodes > defining at what level they're checked (production, debug, never), > which is compared to the global check level (off, production, debug), > and what the action is on failure (ignore, log, panic, etc.) > > It's flexible but it's also a bit awkward to work with when you don't > know if one of those VERIFY_ASSERTS will panic or not -- especially > since the error can be ignored. Perhaps we made it too flexible. > > Since KASSERT was always INVARIANTS only this is probably a step in > the right direction (though the rate check means that if one error > fires, other errors of a different type will be ignored). Making it > more fine grained so individual checks can be enabled at runtime > instead of compile time, etc., would be useful to some vendors. But > all that flexibility has a cost in object code and runtime for the > embedded world, so it's a tradeoff too. Yes! :) I've done something in the past for debug where each assert/whatever was under a "subsystem" so you would have ASSERT(subsystem, cond, "message",...). I started thinking about passing __FILE__ in and allowing a table (modifiable via sysctl) of strings to compare against to decide "panic" "log" "ignore", but then I realized that should wait for another day after the community looks at the current facility. If people have more ideas I'd love to hear them. -Alfred > > Cheers, > matthew > >> On 7 December 2012 00:25, Alfred Perlstein wrote: >>> Author: alfred >>> Date: Fri Dec 7 08:25:08 2012 >>> New Revision: 243980 >>> URL: http://svnweb.freebsd.org/changeset/base/243980 >>> >>> Log: >>> Allow KASSERT to log instead of panic. >>> >>> This is to allow debug images to be used without taking down the >>> system when non-fatal asserts are hit. >>> >>> The following sysctls are added: >>> >>> debug.kassert.warn_only: 1 = log, 0 = panic >>> >>> debug.kassert.do_ktr: set to a ktr mask for logging via KTR >>> >>> debug.kassert.do_log: 1 = log, 0 = quiet >>> >>> debug.kassert.warnings: stats, number of kasserts hit >>> >>> debug.kassert.log_panic_at: >>> number of kasserts before we actually panic, 0 = never >>> >>> debug.kassert.log_pps_limit: pps limit for log messages >>> >>> debug.kassert.log_mute_at: stop warning after N kasserts, 0 = never stop >>> >>> debug.kassert.kassert: set this sysctl to trigger a kassert >>> >>> Discussed with: scottl, gnn, marcel >>> Sponsored by: iXsystems >>> >>> Modified: >>> head/sys/kern/kern_shutdown.c >>> head/sys/sys/systm.h >>> >>> Modified: head/sys/kern/kern_shutdown.c >>> ============================================================================== >>> --- head/sys/kern/kern_shutdown.c Fri Dec 7 07:24:15 2012 (r243979) >>> +++ head/sys/kern/kern_shutdown.c Fri Dec 7 08:25:08 2012 (r243980) >>> @@ -55,6 +55,7 @@ __FBSDID("$FreeBSD$"); >>> #include >>> #include >>> #include >>> +#include >>> #include >>> #include >>> #include >>> @@ -150,6 +151,7 @@ static void poweroff_wait(void *, int); >>> static void shutdown_halt(void *junk, int howto); >>> static void shutdown_panic(void *junk, int howto); >>> static void shutdown_reset(void *junk, int howto); >>> +static void vpanic(const char *fmt, va_list ap) __dead2; >>> >>> /* register various local shutdown events */ >>> static void >>> @@ -538,6 +540,120 @@ shutdown_reset(void *junk, int howto) >>> /* NOTREACHED */ /* assuming reset worked */ >>> } >>> >>> +#ifdef INVARIANTS >>> +static int kassert_warn_only = 0; >>> +#ifdef KTR >>> +static int kassert_do_ktr = 0; >>> +#endif >>> +static int kassert_do_log = 1; >>> +static int kassert_log_pps_limit = 4; >>> +static int kassert_log_mute_at = 0; >>> +static int kassert_log_panic_at = 0; >>> +static int kassert_warnings = 0; >>> + >>> +SYSCTL_NODE(_debug, OID_AUTO, kassert, CTLFLAG_RW, NULL, "kassert options"); >>> + >>> +SYSCTL_INT(_debug_kassert, OID_AUTO, warn_only, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_warn_only, 0, >>> + "KASSERT triggers a panic (1) or just a warning (0)"); >>> +TUNABLE_INT("debug.kassert.warn_only", &kassert_warn_only); >>> + >>> +#ifdef KTR >>> +SYSCTL_UINT(_debug_kassert, OID_AUTO, do_ktr, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_do_ktr, 0, >>> + "KASSERT does a KTR, set this to the KTRMASK you want"); >>> +TUNABLE_INT("debug.kassert.do_ktr", &kassert_do_ktr); >>> +#endif >>> + >>> +SYSCTL_INT(_debug_kassert, OID_AUTO, do_log, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_do_log, 0, "KASSERT triggers a panic (1) or just a warning (0)"); >>> +TUNABLE_INT("debug.kassert.do_log", &kassert_do_log); >>> + >>> +SYSCTL_INT(_debug_kassert, OID_AUTO, warnings, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_warnings, 0, "number of KASSERTs that have been triggered"); >>> +TUNABLE_INT("debug.kassert.warnings", &kassert_warnings); >>> + >>> +SYSCTL_INT(_debug_kassert, OID_AUTO, log_panic_at, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_log_panic_at, 0, "max number of KASSERTS before we will panic"); >>> +TUNABLE_INT("debug.kassert.log_panic_at", &kassert_log_panic_at); >>> + >>> +SYSCTL_INT(_debug_kassert, OID_AUTO, log_pps_limit, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_log_pps_limit, 0, "limit number of log messages per second"); >>> +TUNABLE_INT("debug.kassert.log_pps_limit", &kassert_log_pps_limit); >>> + >>> +SYSCTL_INT(_debug_kassert, OID_AUTO, log_mute_at, CTLFLAG_RW | CTLFLAG_TUN, >>> + &kassert_log_mute_at, 0, "max number of KASSERTS to log"); >>> +TUNABLE_INT("debug.kassert.log_mute_at", &kassert_log_mute_at); >>> + >>> +static int kassert_sysctl_kassert(SYSCTL_HANDLER_ARGS); >>> + >>> +SYSCTL_PROC(_debug_kassert, OID_AUTO, kassert, >>> + CTLTYPE_INT | CTLFLAG_RW | CTLFLAG_SECURE, NULL, 0, >>> + kassert_sysctl_kassert, "I", "set to trigger a test kassert"); >>> + >>> +static int >>> +kassert_sysctl_kassert(SYSCTL_HANDLER_ARGS) >>> +{ >>> + int error, i; >>> + >>> + error = sysctl_wire_old_buffer(req, sizeof(int)); >>> + if (error == 0) { >>> + i = 0; >>> + error = sysctl_handle_int(oidp, &i, 0, req); >>> + } >>> + if (error != 0 || req->newptr == NULL) >>> + return (error); >>> + KASSERT(0, ("kassert_sysctl_kassert triggered kassert %d", i)); >>> + return (0); >>> +} >>> + >>> +/* >>> + * Called by KASSERT, this decides if we will panic >>> + * or if we will log via printf and/or ktr. >>> + */ >>> +void >>> +kassert_panic(const char *fmt, ...) >>> +{ >>> + static char buf[256]; >>> + va_list ap; >>> + >>> + va_start(ap, fmt); >>> + (void)vsnprintf(buf, sizeof(buf), fmt, ap); >>> + va_end(ap); >>> + >>> + /* >>> + * panic if we're not just warning, or if we've exceeded >>> + * kassert_log_panic_at warnings. >>> + */ >>> + if (!kassert_warn_only || >>> + (kassert_log_panic_at > 0 && >>> + kassert_warnings >= kassert_log_panic_at)) { >>> + va_start(ap, fmt); >>> + vpanic(fmt, ap); >>> + /* NORETURN */ >>> + } >>> +#ifdef KTR >>> + if (kassert_do_ktr) >>> + CTR0(ktr_mask, buf); >>> +#endif /* KTR */ >>> + /* >>> + * log if we've not yet met the mute limit. >>> + */ >>> + if (kassert_do_log && >>> + (kassert_log_mute_at == 0 || >>> + kassert_warnings < kassert_log_mute_at)) { >>> + static struct timeval lasterr; >>> + static int curerr; >>> + >>> + if (ppsratecheck(&lasterr, &curerr, kassert_log_pps_limit)) { >>> + printf("KASSERT failed: %s\n", buf); >>> + kdb_backtrace(); >>> + } >>> + } >>> + atomic_add_int(&kassert_warnings, 1); >>> +} >>> +#endif >>> + >>> /* >>> * Panic is called on unresolvable fatal errors. It prints "panic: mesg", >>> * and then reboots. If we are called twice, then we avoid trying to sync >>> @@ -546,12 +662,20 @@ shutdown_reset(void *junk, int howto) >>> void >>> panic(const char *fmt, ...) >>> { >>> + va_list ap; >>> + >>> + va_start(ap, fmt); >>> + vpanic(fmt, ap); >>> +} >>> + >>> +static void >>> +vpanic(const char *fmt, va_list ap) >>> +{ >>> #ifdef SMP >>> cpuset_t other_cpus; >>> #endif >>> struct thread *td = curthread; >>> int bootopt, newpanic; >>> - va_list ap; >>> static char buf[256]; >>> >>> spinlock_enter(); >>> @@ -587,7 +711,6 @@ panic(const char *fmt, ...) >>> newpanic = 1; >>> } >>> >>> - va_start(ap, fmt); >>> if (newpanic) { >>> (void)vsnprintf(buf, sizeof(buf), fmt, ap); >>> panicstr = buf; >>> @@ -598,7 +721,6 @@ panic(const char *fmt, ...) >>> vprintf(fmt, ap); >>> printf("\n"); >>> } >>> - va_end(ap); >>> #ifdef SMP >>> printf("cpuid = %d\n", PCPU_GET(cpuid)); >>> #endif >>> >>> Modified: head/sys/sys/systm.h >>> ============================================================================== >>> --- head/sys/sys/systm.h Fri Dec 7 07:24:15 2012 (r243979) >>> +++ head/sys/sys/systm.h Fri Dec 7 08:25:08 2012 (r243980) >>> @@ -73,14 +73,16 @@ extern int vm_guest; /* Running as virt >>> enum VM_GUEST { VM_GUEST_NO = 0, VM_GUEST_VM, VM_GUEST_XEN }; >>> >>> #ifdef INVARIANTS /* The option is always available */ >>> +void kassert_panic(const char *fmt, ...); >>> + >>> #define KASSERT(exp,msg) do { \ >>> if (__predict_false(!(exp))) \ >>> - panic msg; \ >>> + kassert_panic msg; \ >>> } while (0) >>> #define VNASSERT(exp, vp, msg) do { \ >>> if (__predict_false(!(exp))) { \ >>> vn_printf(vp, "VNASSERT failed\n"); \ >>> - panic msg; \ >>> + kassert_panic msg; \ >>> } \ >>> } while (0) >>> #else >> _______________________________________________ >> freebsd-arch@freebsd.org mailing list >> http://lists.freebsd.org/mailman/listinfo/freebsd-arch >> To unsubscribe, send any mail to "freebsd-arch-unsubscribe@freebsd.org"