[PATCH v2] clocksource: Warn if too many missing ticks are detected

[PATCH v2] clocksource: Warn if too many missing ticks are detected

[Waiman Long]

The clocksource watchdog, when running, is scheduled on all the CPUs in
the system sequentially on a round-robin fashion with a period of 0.5s.
A bug in the 4.18 kernel is causing missing ticks when nohz_full
is specified. Under some circumstances, this causes the watchdog to
incorrectly state that the TSC is unstable because of counter overflow
in the hpet watchdog clock source after a few minutes delay.

That particular bug is fixed by the 4.19 commit 7059b36636beab ("sched:
idle: Avoid retaining the tick when it has been stopped"). To make it
easier to catch this kind of bug in the future, a check is added to see
if there is too much delay in the invocation of the watchdog callback
and print a warning once if it happens.

Signed-off-by: Waiman Long <longman@redhat.com>
---
 kernel/time/clocksource.c | 12 ++++++++++++
 1 file changed, 12 insertions(+)

diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
index 0e6e97a..64b05ab 100644
--- a/kernel/time/clocksource.c
+++ b/kernel/time/clocksource.c
@@ -213,6 +213,18 @@ static void clocksource_watchdog(struct timer_list *unused)
 	if (!watchdog_running)
 		goto out;
 
+	/*
+	 * When the timer tick is incorrectly stopped on a CPU with
+	 * pending events, for example, it is possible that the
+	 * clocksource watchdog will stop running for a sufficiently
+	 * long enough time to cause overflow in the delta
+	 * computation leading to incorrect report of unstable clock
+	 * source. So print a warning if there is unusually large
+	 * delay (> 0.5s) in the invocation of the watchdog. That
+	 * can indicate a hidden bug in the timer tick code.
+	 */
+	WARN_ON_ONCE(jiffies - watchdog_timer.expires > WATCHDOG_INTERVAL);
+
 	reset_pending = atomic_read(&watchdog_reset_pending);
 
 	list_for_each_entry(cs, &watchdog_list, wd_list) {
-- 
1.8.3.1

Re: [PATCH v2] clocksource: Warn if too many missing ticks are detected

[Thomas Gleixner]

On Tue, 18 Sep 2018, Waiman Long wrote:

> The clocksource watchdog, when running, is scheduled on all the CPUs in
> the system sequentially on a round-robin fashion with a period of 0.5s.
> A bug in the 4.18 kernel is causing missing ticks when nohz_full
> is specified. Under some circumstances, this causes the watchdog to
> incorrectly state that the TSC is unstable because of counter overflow
> in the hpet watchdog clock source after a few minutes delay.
> 
> That particular bug is fixed by the 4.19 commit 7059b36636beab ("sched:
> idle: Avoid retaining the tick when it has been stopped"). To make it
> easier to catch this kind of bug in the future, a check is added to see
> if there is too much delay in the invocation of the watchdog callback
> and print a warning once if it happens.

Second thoughts on this. Putting the check into the clocksource watchdog is
the wrong place as it's just checking at a place where the symptom
shows. What about putting it right to the source, i.e. in the timer wheel
as it does not depend on the clocksource watchdog being active. The
clocksource watchdog triggering is just one of the symptoms, but in general
timers being massively late is not a good thing.

Thanks,

	tglx

Re: [PATCH v2] clocksource: Warn if too many missing ticks are detected

[Peter Zijlstra]

On Wed, Sep 19, 2018 at 09:53:47AM +0200, Thomas Gleixner wrote:
> On Tue, 18 Sep 2018, Waiman Long wrote:
> 
> > The clocksource watchdog, when running, is scheduled on all the CPUs in
> > the system sequentially on a round-robin fashion with a period of 0.5s.
> > A bug in the 4.18 kernel is causing missing ticks when nohz_full
> > is specified. Under some circumstances, this causes the watchdog to
> > incorrectly state that the TSC is unstable because of counter overflow
> > in the hpet watchdog clock source after a few minutes delay.
> > 
> > That particular bug is fixed by the 4.19 commit 7059b36636beab ("sched:
> > idle: Avoid retaining the tick when it has been stopped"). To make it
> > easier to catch this kind of bug in the future, a check is added to see
> > if there is too much delay in the invocation of the watchdog callback
> > and print a warning once if it happens.
> 
> Second thoughts on this. Putting the check into the clocksource watchdog is
> the wrong place as it's just checking at a place where the symptom
> shows. What about putting it right to the source, i.e. in the timer wheel
> as it does not depend on the clocksource watchdog being active. The
> clocksource watchdog triggering is just one of the symptoms, but in general
> timers being massively late is not a good thing.

Just make sure to think of the virt case; virt can cause all kind of
'fun' lateness.

Re: [PATCH v2] clocksource: Warn if too many missing ticks are detected

[Waiman Long]

On 09/19/2018 05:17 AM, Peter Zijlstra wrote:
> On Wed, Sep 19, 2018 at 09:53:47AM +0200, Thomas Gleixner wrote:
>> On Tue, 18 Sep 2018, Waiman Long wrote:
>>
>>> The clocksource watchdog, when running, is scheduled on all the CPUs in
>>> the system sequentially on a round-robin fashion with a period of 0.5s.
>>> A bug in the 4.18 kernel is causing missing ticks when nohz_full
>>> is specified. Under some circumstances, this causes the watchdog to
>>> incorrectly state that the TSC is unstable because of counter overflow
>>> in the hpet watchdog clock source after a few minutes delay.
>>>
>>> That particular bug is fixed by the 4.19 commit 7059b36636beab ("sched:
>>> idle: Avoid retaining the tick when it has been stopped"). To make it
>>> easier to catch this kind of bug in the future, a check is added to see
>>> if there is too much delay in the invocation of the watchdog callback
>>> and print a warning once if it happens.
>> Second thoughts on this. Putting the check into the clocksource watchdog is
>> the wrong place as it's just checking at a place where the symptom
>> shows. What about putting it right to the source, i.e. in the timer wheel
>> as it does not depend on the clocksource watchdog being active. The
>> clocksource watchdog triggering is just one of the symptoms, but in general
>> timers being massively late is not a good thing.
> Just make sure to think of the virt case; virt can cause all kind of
> 'fun' lateness.

So the question now is how much "lateness" is abnormal? My current patch
just use a 1/2 s threshold. Is that too small or too big?

Cheers,
Longman

Re: [PATCH v2] clocksource: Warn if too many missing ticks are detected

[Waiman Long]

On 09/19/2018 03:53 AM, Thomas Gleixner wrote:
> On Tue, 18 Sep 2018, Waiman Long wrote:
>
>> The clocksource watchdog, when running, is scheduled on all the CPUs in
>> the system sequentially on a round-robin fashion with a period of 0.5s.
>> A bug in the 4.18 kernel is causing missing ticks when nohz_full
>> is specified. Under some circumstances, this causes the watchdog to
>> incorrectly state that the TSC is unstable because of counter overflow
>> in the hpet watchdog clock source after a few minutes delay.
>>
>> That particular bug is fixed by the 4.19 commit 7059b36636beab ("sched:
>> idle: Avoid retaining the tick when it has been stopped"). To make it
>> easier to catch this kind of bug in the future, a check is added to see
>> if there is too much delay in the invocation of the watchdog callback
>> and print a warning once if it happens.
> Second thoughts on this. Putting the check into the clocksource watchdog is
> the wrong place as it's just checking at a place where the symptom
> shows. What about putting it right to the source, i.e. in the timer wheel
> as it does not depend on the clocksource watchdog being active. The
> clocksource watchdog triggering is just one of the symptoms, but in general
> timers being massively late is not a good thing.
>
> Thanks,
>
> 	tglx
>
It looks like there are more complications to deal with in order to do
the proper check. I will leave the check in the watchdog for the time
being and see how thing works out.

-Longman