Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 07 Dec 2012 10:25:53 -0800
From:      Alfred Perlstein <bright@mu.org>
To:        mdf@FreeBSD.org
Cc:        Adrian Chadd <adrian@freebsd.org>, Alfred Perlstein <alfred@freebsd.org>, freebsd-arch@freebsd.org
Subject:   Re: svn commit: r243980 - in head/sys: kern sys
Message-ID:  <50C234B1.6090803@mu.org>
In-Reply-To: <CAMBSHm8NQ0vszsJSet_dBRFcD_xJ3DxCFm0dAYTJMP8zkCeHtg@mail.gmail.com>
References:  <201212070825.qB78P9rY055786@svn.freebsd.org> <CAJ-Vmo=f5fxFzVOUWcXE6GxovH3kTB-UmEkuWc5CkK0ZU%2BQKpA@mail.gmail.com> <CAMBSHm8NQ0vszsJSet_dBRFcD_xJ3DxCFm0dAYTJMP8zkCeHtg@mail.gmail.com>

next in thread | previous in thread | raw e-mail | index | archive | help
On 12/7/12 7:12 AM, mdf@FreeBSD.org wrote:
> On Fri, Dec 7, 2012 at 6:25 AM, Adrian Chadd <adrian@freebsd.org> 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 <alfred@freebsd.org> 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 <sys/kernel.h>
>>>   #include <sys/kerneldump.h>
>>>   #include <sys/kthread.h>
>>> +#include <sys/ktr.h>
>>>   #include <sys/malloc.h>
>>>   #include <sys/mount.h>
>>>   #include <sys/priv.h>
>>> @@ -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"




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?50C234B1.6090803>