* [PATCH] clocksource: Warn if too many missing ticks are detected
@ 2018-09-18 18:36 Waiman Long
2018-09-18 21:07 ` Thomas Gleixner
0 siblings, 1 reply; 4+ messages in thread
From: Waiman Long @ 2018-09-18 18:36 UTC (permalink / raw)
To: John Stultz, Thomas Gleixner
Cc: linux-kernel, Stephen Boyd, Peter Zijlstra, 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 watchdog invocation and print a
warning once if it happens.
Signed-off-by: Waiman Long <longman@redhat.com>
---
kernel/time/clocksource.c | 13 +++++++++++++
1 file changed, 13 insertions(+)
diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
index 0e6e97a..2ea5db0 100644
--- a/kernel/time/clocksource.c
+++ b/kernel/time/clocksource.c
@@ -140,6 +140,7 @@ static void inline clocksource_watchdog_unlock(unsigned long *flags)
* Interval: 0.5sec Threshold: 0.0625s
*/
#define WATCHDOG_INTERVAL (HZ >> 1)
+#define WATCHDOG_INTERNVAL_NS (NSEC_PER_SEC >> 1)
#define WATCHDOG_THRESHOLD (NSEC_PER_SEC >> 4)
static void clocksource_watchdog_work(struct work_struct *work)
@@ -242,6 +243,18 @@ static void clocksource_watchdog(struct timer_list *unused)
wd_nsec = clocksource_cyc2ns(delta, watchdog->mult,
watchdog->shift);
+ /*
+ * 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(!wd_nsec || wd_nsec > 2*WATCHDOG_INTERNVAL_NS);
+
delta = clocksource_delta(csnow, cs->cs_last, cs->mask);
cs_nsec = clocksource_cyc2ns(delta, cs->mult, cs->shift);
wdlast = cs->wd_last; /* save these in case we print them */
--
1.8.3.1
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH] clocksource: Warn if too many missing ticks are detected
2018-09-18 18:36 [PATCH] clocksource: Warn if too many missing ticks are detected Waiman Long
@ 2018-09-18 21:07 ` Thomas Gleixner
2018-09-18 21:54 ` Waiman Long
0 siblings, 1 reply; 4+ messages in thread
From: Thomas Gleixner @ 2018-09-18 21:07 UTC (permalink / raw)
To: Waiman Long; +Cc: John Stultz, linux-kernel, Stephen Boyd, Peter Zijlstra
Waiman,
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 watchdog invocation and print a
> warning once if it happens.
I like the idea.
>
> Signed-off-by: Waiman Long <longman@redhat.com>
> ---
> kernel/time/clocksource.c | 13 +++++++++++++
> 1 file changed, 13 insertions(+)
>
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index 0e6e97a..2ea5db0 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -140,6 +140,7 @@ static void inline clocksource_watchdog_unlock(unsigned long *flags)
> * Interval: 0.5sec Threshold: 0.0625s
> */
> #define WATCHDOG_INTERVAL (HZ >> 1)
> +#define WATCHDOG_INTERNVAL_NS (NSEC_PER_SEC >> 1)
> #define WATCHDOG_THRESHOLD (NSEC_PER_SEC >> 4)
>
> static void clocksource_watchdog_work(struct work_struct *work)
> @@ -242,6 +243,18 @@ static void clocksource_watchdog(struct timer_list *unused)
> wd_nsec = clocksource_cyc2ns(delta, watchdog->mult,
> watchdog->shift);
>
> + /*
> + * 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(!wd_nsec || wd_nsec > 2*WATCHDOG_INTERNVAL_NS);
But this is using the watchdog delta to check. If that wrapped the
detection is broken.
I'd rather use watchdog_timer.expires and check against jiffies. That tells
you how late the timer callback actually is and does not suffer any
wraparound issues.
Thanks,
tglx
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] clocksource: Warn if too many missing ticks are detected
2018-09-18 21:07 ` Thomas Gleixner
@ 2018-09-18 21:54 ` Waiman Long
2018-09-18 22:06 ` Thomas Gleixner
0 siblings, 1 reply; 4+ messages in thread
From: Waiman Long @ 2018-09-18 21:54 UTC (permalink / raw)
To: Thomas Gleixner; +Cc: John Stultz, linux-kernel, Stephen Boyd, Peter Zijlstra
On 09/18/2018 05:07 PM, Thomas Gleixner wrote:
> Waiman,
>
> 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 watchdog invocation and print a
>> warning once if it happens.
> I like the idea.
>
>> Signed-off-by: Waiman Long <longman@redhat.com>
>> ---
>> kernel/time/clocksource.c | 13 +++++++++++++
>> 1 file changed, 13 insertions(+)
>>
>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>> index 0e6e97a..2ea5db0 100644
>> --- a/kernel/time/clocksource.c
>> +++ b/kernel/time/clocksource.c
>> @@ -140,6 +140,7 @@ static void inline clocksource_watchdog_unlock(unsigned long *flags)
>> * Interval: 0.5sec Threshold: 0.0625s
>> */
>> #define WATCHDOG_INTERVAL (HZ >> 1)
>> +#define WATCHDOG_INTERNVAL_NS (NSEC_PER_SEC >> 1)
>> #define WATCHDOG_THRESHOLD (NSEC_PER_SEC >> 4)
>>
>> static void clocksource_watchdog_work(struct work_struct *work)
>> @@ -242,6 +243,18 @@ static void clocksource_watchdog(struct timer_list *unused)
>> wd_nsec = clocksource_cyc2ns(delta, watchdog->mult,
>> watchdog->shift);
>>
>> + /*
>> + * 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(!wd_nsec || wd_nsec > 2*WATCHDOG_INTERNVAL_NS);
> But this is using the watchdog delta to check. If that wrapped the
> detection is broken.
>
> I'd rather use watchdog_timer.expires and check against jiffies. That tells
> you how late the timer callback actually is and does not suffer any
> wraparound issues.
The clocksource_delta() function will deal with wrap-around in the
counter value. It is only when the counter advances more than 0x80000000
for 32-bit hpet counter mask that a value of 0 will be returned. That is
why I have a !wd_nsec check there. There is a small chance when the
warparound is just within the 1 second window that the test fails. In
this case, the following kind of warning will certainly be triggered:
[ 578.890937] clocksource: timekeeping watchdog on CPU21: Marking
clocksource 'tsc' as unstable because the skew is too large:
[ 578.890938] clocksource: 'hpet' wd_now:
ee332105 wd_last: 544f80e7 mask: ffffffff
[ 578.890939] clocksource: 'tsc' cs_now:
4b6e6ccb5d609 cs_last: 4b679a469d09e mask: ffffffffffffffff
[ 578.890954] tsc: Marking TSC unstable due to clocksource watchdog
[ 578.890963] TSC found unstable after boot, most likely due to broken
BIOS. Use 'tsc=unstable'.
[ 578.890965] sched_clock: Marking unstable (578920214163,
-28725675)<-(579047174801, -156217937)
[ 578.891056] clocksource: Switched to clocksource hpet
Another reason that I used wd_nsec is because the data has already been
computed.
I am perfectly fine to use the watchdog_timer.expires as suggested, though.
Cheers,
Longman
watchdog_timer.expires
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] clocksource: Warn if too many missing ticks are detected
2018-09-18 21:54 ` Waiman Long
@ 2018-09-18 22:06 ` Thomas Gleixner
0 siblings, 0 replies; 4+ messages in thread
From: Thomas Gleixner @ 2018-09-18 22:06 UTC (permalink / raw)
To: Waiman Long; +Cc: John Stultz, linux-kernel, Stephen Boyd, Peter Zijlstra
On Tue, 18 Sep 2018, Waiman Long wrote:
> On 09/18/2018 05:07 PM, Thomas Gleixner wrote:
> > On Tue, 18 Sep 2018, Waiman Long wrote:
> >> --- a/kernel/time/clocksource.c
> >> +++ b/kernel/time/clocksource.c
> >> @@ -140,6 +140,7 @@ static void inline clocksource_watchdog_unlock(unsigned long *flags)
> >> * Interval: 0.5sec Threshold: 0.0625s
> >> */
> >> #define WATCHDOG_INTERVAL (HZ >> 1)
> >> +#define WATCHDOG_INTERNVAL_NS (NSEC_PER_SEC >> 1)
> >> #define WATCHDOG_THRESHOLD (NSEC_PER_SEC >> 4)
> >>
> >> static void clocksource_watchdog_work(struct work_struct *work)
> >> @@ -242,6 +243,18 @@ static void clocksource_watchdog(struct timer_list *unused)
> >> wd_nsec = clocksource_cyc2ns(delta, watchdog->mult,
> >> watchdog->shift);
> >>
> >> + /*
> >> + * 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(!wd_nsec || wd_nsec > 2*WATCHDOG_INTERNVAL_NS);
> > But this is using the watchdog delta to check. If that wrapped the
> > detection is broken.
> >
> > I'd rather use watchdog_timer.expires and check against jiffies. That tells
> > you how late the timer callback actually is and does not suffer any
> > wraparound issues.
>
> The clocksource_delta() function will deal with wrap-around in the
> counter value. It is only when the counter advances more than 0x80000000
> for 32-bit hpet counter mask that a value of 0 will be returned. That is
> why I have a !wd_nsec check there. There is a small chance when the
> warparound is just within the 1 second window that the test fails. In
> this case, the following kind of warning will certainly be triggered:
Ok.
> [ 578.890937] clocksource: timekeeping watchdog on CPU21: Marking
> clocksource 'tsc' as unstable because the skew is too large:
> [ 578.890938] clocksource: 'hpet' wd_now:
> ee332105 wd_last: 544f80e7 mask: ffffffff
> [ 578.890939] clocksource: 'tsc' cs_now:
> 4b6e6ccb5d609 cs_last: 4b679a469d09e mask: ffffffffffffffff
> [ 578.890954] tsc: Marking TSC unstable due to clocksource watchdog
> [ 578.890963] TSC found unstable after boot, most likely due to broken
> BIOS. Use 'tsc=unstable'.
> [ 578.890965] sched_clock: Marking unstable (578920214163,
> -28725675)<-(579047174801, -156217937)
> [ 578.891056] clocksource: Switched to clocksource hpet
>
> Another reason that I used wd_nsec is because the data has already been
> computed.
Sure, but that's hardly a hotpath.
> I am perfectly fine to use the watchdog_timer.expires as suggested, though.
I really prefer that because it's just more robust and obvious. No head
scratching about correctness required.
Thanks,
tglx
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-09-18 22:06 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-09-18 18:36 [PATCH] clocksource: Warn if too many missing ticks are detected Waiman Long
2018-09-18 21:07 ` Thomas Gleixner
2018-09-18 21:54 ` Waiman Long
2018-09-18 22:06 ` Thomas Gleixner
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).