[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <b4312465-91b1-4d05-ab77-703396c81d21@redhat.com>
Date: Fri, 4 Nov 2022 22:49:13 -0400
From: Waiman Long <longman@...hat.com>
To: paulmck@...nel.org
Cc: tglx@...utronix.de, linux-kernel@...r.kernel.org,
john.stultz@...aro.org, sboyd@...nel.org, corbet@....net,
Mark.Rutland@....com, maz@...nel.org, kernel-team@...a.com,
neeraju@...eaurora.org, ak@...ux.intel.com, feng.tang@...el.com,
zhengjun.xing@...el.com, John Stultz <jstultz@...gle.com>
Subject: Re: [PATCH clocksource 2/2] clocksource: Exponential backoff for
load-induced bogus watchdog reads
On 11/4/22 22:38, Paul E. McKenney wrote:
> On Fri, Nov 04, 2022 at 09:55:02AM -0400, Waiman Long wrote:
>> On 11/3/22 22:23, Paul E. McKenney wrote:
>>> On Thu, Nov 03, 2022 at 09:01:45PM -0400, Waiman Long wrote:
>>>> On 11/3/22 20:26, Paul E. McKenney wrote:
>>>>> On Thu, Nov 03, 2022 at 08:20:27PM -0400, Waiman Long wrote:
>>>>>> On 11/3/22 16:49, Paul E. McKenney wrote:
> [ . . . ]
>
>>>>>>> + 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?
>>>> OK, I think the word "additional" tricks me into thinking about extra bogus
>>>> messages in additional to the current one. Using another word like "total"
>>>> may be less confusing.
>>> My concern with "total" is that people might think that the numbers
>>> meant the total number of instances since boot.
>>>
>>> So how about "(9 since last message)" or similar?
>>>
>>> Thanx, Paul
>> Yes, that looks good to me.
> Thank you, and please see below for the updated patch.
>
> Thanx, Paul
>
> ------------------------------------------------------------------------
>
> commit a7dc308e8359eafb58df360e06b66ecbf79a4d0b
> Author: Paul E. McKenney <paulmck@...nel.org>
> 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@...hat.com>
> Reported-by: Feng Tang <feng.tang@...el.com>
> Signed-off-by: Paul E. McKenney <paulmck@...nel.org>
> Reviewed-by: Feng Tang <feng.tang@...el.com>
> Cc: John Stultz <jstultz@...gle.com>
> Cc: Thomas Gleixner <tglx@...utronix.de>
> Cc: Stephen Boyd <sboyd@...nel.org>
> Cc: Waiman Long <longman@...hat.com>
>
> 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..4015ec6503a52 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 since last message), probable CPU overutilization, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL, cs->wd_bogus_count);
> + cs->wd_last_bogus = wdnow;
> + if (cs->wd_bogus_shift < 10)
> + cs->wd_bogus_shift++;
> + cs->wd_bogus_count = 0;
> + }
> continue;
> }
> - if (wd_nsec > (wdi << 2)) {
> - /* 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, probable CPU overutilization, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL);
> + /* Check too-short measurements second to handle wrap. */
> + if (wd_nsec < (wdi >> 2) || cs_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);
> continue;
> }
>
>
Looks good to me.
Reviewed-by: Waiman Long <longman@...hat.com>
Powered by blists - more mailing lists