Re: [PATCH -rcu 2/2] kcsan: Rate-limit reporting per data races

[Paul E. McKenney]

On Fri, Jan 10, 2020 at 07:54:09PM +0100, Marco Elver wrote:
> On Fri, 10 Jan 2020 at 19:20, Marco Elver <elver@xxxxxxxxxx> wrote:
> >
> > On Thu, 9 Jan 2020 at 16:23, Marco Elver <elver@xxxxxxxxxx> wrote:
> > >
> > > Adds support for rate limiting reports. This uses a time based rate
> > > limit, that limits any given data race report to no more than one in a
> > > fixed time window (default is 3 sec). This should prevent the console
> > > from being spammed with data race reports, that would render the system
> > > unusable.
> > >
> > > The implementation assumes that unique data races and the rate at which
> > > they occur is bounded, since we cannot store arbitrarily many past data
> > > race report information: we use a fixed-size array to store the required
> > > information. We cannot use kmalloc/krealloc and resize the list when
> > > needed, as reporting is triggered by the instrumentation calls; to
> > > permit using KCSAN on the allocators, we cannot (re-)allocate any memory
> > > during report generation (data races in the allocators lead to
> > > deadlock).
> > >
> > > Reported-by: Qian Cai <cai@xxxxxx>
> > > Suggested-by: Paul E. McKenney <paulmck@xxxxxxxxxx>
> > > Signed-off-by: Marco Elver <elver@xxxxxxxxxx>
> > > ---
> > >  kernel/kcsan/report.c | 112 ++++++++++++++++++++++++++++++++++++++----
> > >  lib/Kconfig.kcsan     |  10 ++++
> > >  2 files changed, 112 insertions(+), 10 deletions(-)
> > >
> > > diff --git a/kernel/kcsan/report.c b/kernel/kcsan/report.c
> > > index 9f503ca2ff7a..e324af7d14c9 100644
> > > --- a/kernel/kcsan/report.c
> > > +++ b/kernel/kcsan/report.c
> > > @@ -1,6 +1,7 @@
> > >  // SPDX-License-Identifier: GPL-2.0
> > >
> > >  #include <linux/kernel.h>
> > > +#include <linux/ktime.h>
> > >  #include <linux/preempt.h>
> > >  #include <linux/printk.h>
> > >  #include <linux/sched.h>
> > > @@ -31,12 +32,101 @@ static struct {
> > >         int                     num_stack_entries;
> > >  } other_info = { .ptr = NULL };
> > >
> > > +/*
> > > + * Information about reported data races; used to rate limit reporting.
> > > + */
> > > +struct report_time {
> > > +       /*
> > > +        * The last time the data race was reported.
> > > +        */
> > > +       ktime_t time;
> > > +
> > > +       /*
> > > +        * The frames of the 2 threads; if only 1 thread is known, one frame
> > > +        * will be 0.
> > > +        */
> > > +       unsigned long frame1;
> > > +       unsigned long frame2;
> > > +};
> > > +
> > > +/*
> > > + * Since we also want to be able to debug allocators with KCSAN, to avoid
> > > + * deadlock, report_times cannot be dynamically resized with krealloc in
> > > + * rate_limit_report.
> > > + *
> > > + * Therefore, we use a fixed-size array, which at most will occupy a page. This
> > > + * still adequately rate limits reports, assuming that a) number of unique data
> > > + * races is not excessive, and b) occurrence of unique data races within the
> > > + * same time window is limited.
> > > + */
> > > +#define REPORT_TIMES_MAX (PAGE_SIZE / sizeof(struct report_time))
> > > +#define REPORT_TIMES_SIZE                                                      \
> > > +       (CONFIG_KCSAN_REPORT_ONCE_IN_MS > REPORT_TIMES_MAX ?                   \
> > > +                REPORT_TIMES_MAX :                                            \
> > > +                CONFIG_KCSAN_REPORT_ONCE_IN_MS)
> > > +static struct report_time report_times[REPORT_TIMES_SIZE];
> > > +
> > >  /*
> > >   * This spinlock protects reporting and other_info, since other_info is usually
> > >   * required when reporting.
> > >   */
> > >  static DEFINE_SPINLOCK(report_lock);
> > >
> > > +/*
> > > + * Checks if the data race identified by thread frames frame1 and frame2 has
> > > + * been reported since (now - KCSAN_REPORT_ONCE_IN_MS).
> > > + */
> > > +static bool rate_limit_report(unsigned long frame1, unsigned long frame2)
> > > +{
> > > +       struct report_time *use_entry = &report_times[0];
> > > +       ktime_t now;
> > > +       ktime_t invalid_before;
> > > +       int i;
> > > +
> > > +       BUILD_BUG_ON(CONFIG_KCSAN_REPORT_ONCE_IN_MS != 0 && REPORT_TIMES_SIZE == 0);
> > > +
> > > +       if (CONFIG_KCSAN_REPORT_ONCE_IN_MS == 0)
> > > +               return false;
> > > +
> > > +       now = ktime_get();
> > > +       invalid_before = ktime_sub_ms(now, CONFIG_KCSAN_REPORT_ONCE_IN_MS);
> >
> > Been thinking about this a bit more, and wondering if we should just
> > use jiffies here?  Don't think we need the precision.
> 
> Sent v2: http://lkml.kernel.org/r/20200110184834.192636-1-elver@xxxxxxxxxx
> I think it's also safer to use jiffies, as noted in the v2 patch.
> 
> Paul: sorry for sending v2, seeing you already had these in your tree.
> Hope this is ok.

Not a problem!  Pulling in the replacements shortly.

							Thanx, Paul