Re: [PATCH clocksource 2/2] clocksource: Exponential backoff for load-induced bogus watchdog reads

From: Paul E. McKenney
Date: Thu Nov 03 2022 - 20:26:23 EST


On Thu, Nov 03, 2022 at 08:20:27PM -0400, Waiman Long wrote:
> On 11/3/22 16:49, Paul E. McKenney wrote:
> > commit da44b8af99222ff8761a98ca8c00837a7d607d28
> > Author: Paul E. McKenney<paulmck@xxxxxxxxxx>
> > Date: Fri Oct 28 10:38:58 2022 -0700
> >
> > clocksource: Exponential backoff for load-induced bogus watchdog reads
> > The clocksource watchdog will reject measurements that are excessively
> > delayed, that is, by more than 1.5 seconds beyond the intended 0.5-second
> > watchdog interval. On an extremely busy system, this can result in a
> > console message being printed every two seconds. This is excessively
> > noisy for a non-error condition.
> > Therefore, apply exponential backoff to these messages. This exponential
> > backoff is capped at 1024 times the watchdog interval, which comes to
> > not quite one message per ten minutes.
> > Please note that the bogus watchdog reads that occur when the watchdog
> > interval is less than 0.125 seconds are still printed unconditionally
> > because these likely correspond to a serious error condition in the
> > timer code or hardware.
> > [ paulmck: Apply Feng Tang feedback. ]
> > [ paulmck: Apply Waiman Long feedback. ]
> > Reported-by: Waiman Long<longman@xxxxxxxxxx>
> > Reported-by: Feng Tang<feng.tang@xxxxxxxxx>
> > Signed-off-by: Paul E. McKenney<paulmck@xxxxxxxxxx>
> > Cc: John Stultz<jstultz@xxxxxxxxxx>
> > Cc: Thomas Gleixner<tglx@xxxxxxxxxxxxx>
> > Cc: Stephen Boyd<sboyd@xxxxxxxxxx>
> > Cc: Feng Tang<feng.tang@xxxxxxxxx>
> > Cc: Waiman Long<longman@xxxxxxxxxx>
> >
> > diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
> > index 1d42d4b173271..23b73f2293d6d 100644
> > --- a/include/linux/clocksource.h
> > +++ b/include/linux/clocksource.h
> > @@ -125,6 +125,9 @@ struct clocksource {
> > struct list_head wd_list;
> > u64 cs_last;
> > u64 wd_last;
> > + u64 wd_last_bogus;
> > + int wd_bogus_shift;
> > + unsigned long wd_bogus_count;
> > #endif
> > struct module *owner;
> > };
> > diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > index 3f5317faf891f..1eefb56505350 100644
> > --- a/kernel/time/clocksource.c
> > +++ b/kernel/time/clocksource.c
> > @@ -442,14 +442,33 @@ static void clocksource_watchdog(struct timer_list *unused)
> > /* Check for bogus measurements. */
> > wdi = jiffies_to_nsecs(WATCHDOG_INTERVAL);
> > - if (wd_nsec < (wdi >> 2)) {
> > - /* This usually indicates broken timer code or hardware. */
> > - pr_warn("timekeeping watchdog on CPU%d: Watchdog clocksource '%s' advanced only %lld ns during %d-jiffy time interval, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL);
> > + if (wd_nsec > (wdi << 2) || cs_nsec > (wdi << 2)) {
> > + bool needwarn = false;
> > + u64 wd_lb;
> > +
> > + cs->wd_bogus_count++;
> > + if (!cs->wd_bogus_shift) {
> > + needwarn = true;
> > + } else {
> > + delta = clocksource_delta(wdnow, cs->wd_last_bogus, watchdog->mask);
> > + wd_lb = clocksource_cyc2ns(delta, watchdog->mult, watchdog->shift);
> > + if ((1 << cs->wd_bogus_shift) * wdi <= wd_lb)
> > + needwarn = true;
> > + }
> > + if (needwarn) {
> > + /* This can happen on busy systems, which can delay the watchdog. */
> > + pr_warn("timekeeping watchdog on CPU%d: Watchdog clocksource '%s' advanced an excessive %lld ns during %d-jiffy time interval (%lu additional), probable CPU overutilization, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL, cs->wd_bogus_count);
>
> Just one question, does "%lu additional" means the number of bogus count
> that doesn't meet the needwarn requirement and hence skipped. If so, I think
> you have to use "cs->wd_bogus_cnt - 1". Other than that, the change looks
> good to me.

It means the number since the last report, or, for the first report,
the number since boot.

Does that work for you?

Thanx, Paul