Re: [PATCH -rcu 0/2] kcsan: Improvements to reporting

From: Paul E. McKenney
Date: Thu Jan 09 2020 - 15:46:44 EST


On Thu, Jan 09, 2020 at 06:42:16PM +0100, Marco Elver wrote:
> On Thu, 9 Jan 2020 at 18:31, Paul E. McKenney <paulmck@xxxxxxxxxx> wrote:
> >
> > On Thu, Jan 09, 2020 at 06:03:39PM +0100, Marco Elver wrote:
> > > On Thu, 9 Jan 2020 at 17:27, Paul E. McKenney <paulmck@xxxxxxxxxx> wrote:
> > > >
> > > > On Thu, Jan 09, 2020 at 04:23:20PM +0100, Marco Elver wrote:
> > > > > Improvements to KCSAN data race reporting:
> > > > > 1. Show if access is marked (*_ONCE, atomic, etc.).
> > > > > 2. Rate limit reporting to avoid spamming console.
> > > > >
> > > > > Marco Elver (2):
> > > > > kcsan: Show full access type in report
> > > > > kcsan: Rate-limit reporting per data races
> > > >
> > > > Queued and pushed, thank you! I edited the commit logs a bit, so could
> > > > you please check to make sure that I didn't mess anything up?
> > >
> > > Looks good to me, thank you.
> > >
> > > > At some point, boot-time-allocated per-CPU arrays might be needed to
> > > > avoid contention on large systems, but one step at a time. ;-)
> > >
> > > I certainly hope the rate of fixing/avoiding data races will not be
> > > eclipsed by the rate at which new ones are introduced. :-)
> >
> > Me too!
> >
> > However, on a large system, duplicate reports might happen quite
> > frequently, which might cause slowdowns given the single global
> > array. Or maybe not -- I guess we will find out soon enough. ;-)
> >
> > But I must confess that I am missing how concurrent access to the
> > report_times[] array is handled. I would have expected that
> > rate_limit_report() would choose a random starting entry and
> > search circularly. And I would expect that the code at the end
> > of that function would instead look something like this:
> >
> > if (ktime_before(oldtime, invalid_before) &&
> > cmpxchg(&use_entry->time, oldtime, now) == oldtime) {
> > use_entry->frame1 = frame1;
> > use_entry->frame2 = frame2;
> > } else {
> > // Too bad, next duplicate report won't be suppressed.
> > }
> >
> > Where "oldtime" is captured from the entry during the scan, and from the
> > first entry scanned. This cmpxchg() approach is of course vulnerable
> > to the ->frame1 and ->frame2 assignments taking more than three seconds
> > (by default), but if that becomes a problem, a WARN_ON() could be added:
> >
> > if (ktime_before(oldtime, invalid_before) &&
> > cmpxchg(&use_entry->time, oldtime, now) == oldtime) {
> > use_entry->frame1 = frame1;
> > use_entry->frame2 = frame2;
> > WARN_ON_ONCE(use_entry->time != now);
> > } else {
> > // Too bad, next duplicate report won't be suppressed.
> > }
> >
> > So what am I missing here?
>
> Ah right, sorry, I should have clarified or commented in the code that
> all of this is happening under 'report_lock' (taken in prepare_report,
> held in print_report->rate_limit_report, released in release_report).
> That also means that any optimization here won't matter until
> report_lock is removed.

Got it, thank you! And yes, lock contention on report_lock might be
a problem on large systems. But let's see how it goes.

Thanx, Paul

> Thanks,
> -- Marco
>
> > Thanx, Paul
> >
> > > Thanks,
> > > -- Marco
> > >
> > > > Thanx, Paul
> > > >
> > > > > kernel/kcsan/core.c | 15 +++--
> > > > > kernel/kcsan/kcsan.h | 2 +-
> > > > > kernel/kcsan/report.c | 153 +++++++++++++++++++++++++++++++++++-------
> > > > > lib/Kconfig.kcsan | 10 +++
> > > > > 4 files changed, 148 insertions(+), 32 deletions(-)
> > > > >
> > > > > --
> > > > > 2.25.0.rc1.283.g88dfdc4193-goog
> > > > >
> > > >
> > > > --
> > > > You received this message because you are subscribed to the Google Groups "kasan-dev" group.
> > > > To unsubscribe from this group and stop receiving emails from it, send an email to kasan-dev+unsubscribe@xxxxxxxxxxxxxxxxx
> > > > To view this discussion on the web visit https://groups.google.com/d/msgid/kasan-dev/20200109162739.GS13449%40paulmck-ThinkPad-P72.