LinuxLists.cc - [PATCH] Clocksource: Avoid misjudgment of clocksource

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>
> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
> Timer. But sometimes system is very busy and the Timer cannot be
> executed in 0.5sec. For example,if clocksource_watchdog be executed
> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
> be enlarged. Then the current clocksource will be misjudged as
> unstable. So we add conditions to prevent the clocksource from
> being misjudged.
>
> Signed-off-by: yanghui <[email protected]>
> ---
> kernel/time/clocksource.c | 6 +++++-
> 1 file changed, 5 insertions(+), 1 deletion(-)
>
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index b8a14d2fb5ba..d535beadcbc8 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>
> /*
> * Interval: 0.5sec.
> + * MaxInterval: 1s.
> */
> #define WATCHDOG_INTERVAL (HZ >> 1)
> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>
> static void clocksource_watchdog_work(struct work_struct *work)
> {
> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>
> /* Check the deviation from the watchdog clocksource. */
> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> - if (abs(cs_nsec - wd_nsec) > md) {
> + if ((abs(cs_nsec - wd_nsec) > md) &&
> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&

Sorry, it's been awhile since I looked at this code, but why are you
bounding the clocksource delta here?
It seems like if the clocksource being watched was very wrong (with a
delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.

> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {

Bounding the watchdog interval on the check does seem reasonable.
Though one may want to keep track that if we are seeing too many of
these delayed watchdog checks we provide some feedback via dmesg.

thanks
-john

2021-10-09 03:23:48

[permalink] [raw]

Subject: Re: [External] Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

在 2021/10/9 上午7:45, John Stultz 写道:
> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>
>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>> Timer. But sometimes system is very busy and the Timer cannot be
>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>> be enlarged. Then the current clocksource will be misjudged as
>> unstable. So we add conditions to prevent the clocksource from
>> being misjudged.
>>
>> Signed-off-by: yanghui <[email protected]>
>> ---
>> kernel/time/clocksource.c | 6 +++++-
>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>
>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>> index b8a14d2fb5ba..d535beadcbc8 100644
>> --- a/kernel/time/clocksource.c
>> +++ b/kernel/time/clocksource.c
>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>
>> /*
>> * Interval: 0.5sec.
>> + * MaxInterval: 1s.
>> */
>> #define WATCHDOG_INTERVAL (HZ >> 1)
>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>
>> static void clocksource_watchdog_work(struct work_struct *work)
>> {
>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>
>> /* Check the deviation from the watchdog clocksource. */
>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>> - if (abs(cs_nsec - wd_nsec) > md) {
>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>
> Sorry, it's been awhile since I looked at this code, but why are you
> bounding the clocksource delta here?
> It seems like if the clocksource being watched was very wrong (with a
> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>
>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>
> Bounding the watchdog interval on the check does seem reasonable.
> Though one may want to keep track that if we are seeing too many of
> these delayed watchdog checks we provide some feedback via dmesg.

Yes, only to check watchdog delta is more reasonable.
I think Only have dmesg is not enough, because if tsc was be misjudged
as unstable then switch to hpet. And hpet is very expensive for
performance, so if we want to switch to tsc the only way is to reboot
the server. We need to prevent the switching of the clock source in
case of misjudgment.
Circumstances of misjudgment:
if clocksource_watchdog is executed after 10sec, the value of wd_delta
and cs_delta also be about 10sec, also the value of (cs_nsec- wd_nsec)
will be magnified 20 times(10sec/0.5sec).The delta value is magnified.
But now clocksource is accurate, the Timer is inaccurate. So we
misjudged the clocksource. We need avoid this from happening.

thanks
-Hui
>
> thanks
> -john
>

2021-10-09 03:42:38

[permalink] [raw]

Subject: Re: [External] Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Fri, Oct 8, 2021 at 8:22 PM yanghui <[email protected]> wrote:
> 在 2021/10/9 上午7:45, John Stultz 写道:
> > On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
> >>
> >> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
> >> Timer. But sometimes system is very busy and the Timer cannot be
> >> executed in 0.5sec. For example,if clocksource_watchdog be executed
> >> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
> >> be enlarged. Then the current clocksource will be misjudged as
> >> unstable. So we add conditions to prevent the clocksource from
> >> being misjudged.
> >>
> >> Signed-off-by: yanghui <[email protected]>
> >> ---
> >> kernel/time/clocksource.c | 6 +++++-
> >> 1 file changed, 5 insertions(+), 1 deletion(-)
> >>
> >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> >> index b8a14d2fb5ba..d535beadcbc8 100644
> >> --- a/kernel/time/clocksource.c
> >> +++ b/kernel/time/clocksource.c
> >> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
> >>
> >> /*
> >> * Interval: 0.5sec.
> >> + * MaxInterval: 1s.
> >> */
> >> #define WATCHDOG_INTERVAL (HZ >> 1)
> >> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> >>
> >> static void clocksource_watchdog_work(struct work_struct *work)
> >> {
> >> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
> >>
> >> /* Check the deviation from the watchdog clocksource. */
> >> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> >> - if (abs(cs_nsec - wd_nsec) > md) {
> >> + if ((abs(cs_nsec - wd_nsec) > md) &&
> >> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
> >
> > Sorry, it's been awhile since I looked at this code, but why are you
> > bounding the clocksource delta here?
> > It seems like if the clocksource being watched was very wrong (with a
> > delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
> >
> >> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
> >
> > Bounding the watchdog interval on the check does seem reasonable.
> > Though one may want to keep track that if we are seeing too many of
> > these delayed watchdog checks we provide some feedback via dmesg.
>
> Yes, only to check watchdog delta is more reasonable.
> I think Only have dmesg is not enough, because if tsc was be misjudged
> as unstable then switch to hpet. And hpet is very expensive for
> performance, so if we want to switch to tsc the only way is to reboot
> the server. We need to prevent the switching of the clock source in
> case of misjudgment.
> Circumstances of misjudgment:
> if clocksource_watchdog is executed after 10sec, the value of wd_delta
> and cs_delta also be about 10sec, also the value of (cs_nsec- wd_nsec)
> will be magnified 20 times(10sec/0.5sec).The delta value is magnified.

Yea, it might be worth calculating an error rate instead of assuming
the interval is fixed, but also just skipping the check may be
reasonable assuming timers aren't constantly being delayed (and it's
more of a transient state).

At some point if the watchdog timer is delayed too much, the watchdog
hardware will fully wrap and one can no longer properly compare
intervals. That's why the timer length is chosen as such, so having
that timer delayed is really pushing the system into a potentially bad
state where other subtle problems are likely to crop up.

So I do worry these watchdog robustness fixes are papering over a
problem, pushing expectations closer to the edge of how far the system
should tolerate bad behavior. Because at some point we'll fall off. :)

thanks
-john

2021-10-09 09:05:25

[permalink] [raw]

Subject: Re: [External] Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

在 2021/10/9 上午11:38, John Stultz 写道:
> On Fri, Oct 8, 2021 at 8:22 PM yanghui <[email protected]> wrote:
>> 在 2021/10/9 上午7:45, John Stultz 写道:
>>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>>>
>>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>>>> Timer. But sometimes system is very busy and the Timer cannot be
>>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>>>> be enlarged. Then the current clocksource will be misjudged as
>>>> unstable. So we add conditions to prevent the clocksource from
>>>> being misjudged.
>>>>
>>>> Signed-off-by: yanghui <[email protected]>
>>>> ---
>>>> kernel/time/clocksource.c | 6 +++++-
>>>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>>>
>>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>>> index b8a14d2fb5ba..d535beadcbc8 100644
>>>> --- a/kernel/time/clocksource.c
>>>> +++ b/kernel/time/clocksource.c
>>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>>>
>>>> /*
>>>> * Interval: 0.5sec.
>>>> + * MaxInterval: 1s.
>>>> */
>>>> #define WATCHDOG_INTERVAL (HZ >> 1)
>>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>>>
>>>> static void clocksource_watchdog_work(struct work_struct *work)
>>>> {
>>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>>
>>>> /* Check the deviation from the watchdog clocksource. */
>>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>>> - if (abs(cs_nsec - wd_nsec) > md) {
>>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>>>
>>> Sorry, it's been awhile since I looked at this code, but why are you
>>> bounding the clocksource delta here?
>>> It seems like if the clocksource being watched was very wrong (with a
>>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>>>
>>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>>>
>>> Bounding the watchdog interval on the check does seem reasonable.
>>> Though one may want to keep track that if we are seeing too many of
>>> these delayed watchdog checks we provide some feedback via dmesg.
>>
>> Yes, only to check watchdog delta is more reasonable.
>> I think Only have dmesg is not enough, because if tsc was be misjudged
>> as unstable then switch to hpet. And hpet is very expensive for
>> performance, so if we want to switch to tsc the only way is to reboot
>> the server. We need to prevent the switching of the clock source in
>> case of misjudgment.
>> Circumstances of misjudgment:
>> if clocksource_watchdog is executed after 10sec, the value of wd_delta
>> and cs_delta also be about 10sec, also the value of (cs_nsec- wd_nsec)
>> will be magnified 20 times(10sec/0.5sec).The delta value is magnified.
>
> Yea, it might be worth calculating an error rate instead of assuming
> the interval is fixed, but also just skipping the check may be
> reasonable assuming timers aren't constantly being delayed (and it's
> more of a transient state).
>
> At some point if the watchdog timer is delayed too much, the watchdog
I mean the execution cycle of this function(static void
clocksource_watchdog(struct timer_list *unused)) has been delayed.

> hardware will fully wrap and one can no longer properly compare
> intervals. That's why the timer length is chosen as such, so having
> that timer delayed is really pushing the system into a potentially bad
> state where other subtle problems are likely to crop up.
>
> So I do worry these watchdog robustness fixes are papering over a
> problem, pushing expectations closer to the edge of how far the system
> should tolerate bad behavior. Because at some point we'll fall off. :)

Sorry,I don't seem to understand what you mean. Should I send your Patch
v2 ?

thanks
-hui
>
> thanks
> -john
>

2021-10-09 14:06:37

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

hello

John Stultz wrote on 2021/10/9 7:45:
> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>
>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>> Timer. But sometimes system is very busy and the Timer cannot be
>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>> be enlarged. Then the current clocksource will be misjudged as
>> unstable. So we add conditions to prevent the clocksource from
>> being misjudged.
>>
>> Signed-off-by: yanghui <[email protected]>
>> ---
>> kernel/time/clocksource.c | 6 +++++-
>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>
>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>> index b8a14d2fb5ba..d535beadcbc8 100644
>> --- a/kernel/time/clocksource.c
>> +++ b/kernel/time/clocksource.c
>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>
>> /*
>> * Interval: 0.5sec.
>> + * MaxInterval: 1s.
>> */
>> #define WATCHDOG_INTERVAL (HZ >> 1)
>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>
>> static void clocksource_watchdog_work(struct work_struct *work)
>> {
>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>
>> /* Check the deviation from the watchdog clocksource. */
>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>> - if (abs(cs_nsec - wd_nsec) > md) {
>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>
> Sorry, it's been awhile since I looked at this code, but why are you
> bounding the clocksource delta here?
> It seems like if the clocksource being watched was very wrong (with a
> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>
>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>
> Bounding the watchdog interval on the check does seem reasonable.
> Though one may want to keep track that if we are seeing too many of
> these delayed watchdog checks we provide some feedback via dmesg.

For some fast timeout timers, such as acpi-timer, checking wd_nsec should not
make much sense, because when wacthdog is called, the timer may overflow many
times.

> thanks
> -john
>

2021-10-12 04:58:14

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
>
> hello
>
> John Stultz wrote on 2021/10/9 7:45:
> > On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
> >>
> >> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
> >> Timer. But sometimes system is very busy and the Timer cannot be
> >> executed in 0.5sec. For example,if clocksource_watchdog be executed
> >> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
> >> be enlarged. Then the current clocksource will be misjudged as
> >> unstable. So we add conditions to prevent the clocksource from
> >> being misjudged.
> >>
> >> Signed-off-by: yanghui <[email protected]>
> >> ---
> >> kernel/time/clocksource.c | 6 +++++-
> >> 1 file changed, 5 insertions(+), 1 deletion(-)
> >>
> >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> >> index b8a14d2fb5ba..d535beadcbc8 100644
> >> --- a/kernel/time/clocksource.c
> >> +++ b/kernel/time/clocksource.c
> >> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
> >>
> >> /*
> >> * Interval: 0.5sec.
> >> + * MaxInterval: 1s.
> >> */
> >> #define WATCHDOG_INTERVAL (HZ >> 1)
> >> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> >>
> >> static void clocksource_watchdog_work(struct work_struct *work)
> >> {
> >> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
> >>
> >> /* Check the deviation from the watchdog clocksource. */
> >> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> >> - if (abs(cs_nsec - wd_nsec) > md) {
> >> + if ((abs(cs_nsec - wd_nsec) > md) &&
> >> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
> >
> > Sorry, it's been awhile since I looked at this code, but why are you
> > bounding the clocksource delta here?
> > It seems like if the clocksource being watched was very wrong (with a
> > delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
> >
> >> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
> >
> > Bounding the watchdog interval on the check does seem reasonable.
> > Though one may want to keep track that if we are seeing too many of
> > these delayed watchdog checks we provide some feedback via dmesg.
>
> For some fast timeout timers, such as acpi-timer, checking wd_nsec should not
> make much sense, because when wacthdog is called, the timer may overflow many
> times.

Indeed. But in that case we can't tell which way is up. This is what I
was fretting about when I said:
> So I do worry these watchdog robustness fixes are papering over a
> problem, pushing expectations closer to the edge of how far the system
> should tolerate bad behavior. Because at some point we'll fall off. :)

If the timer is delayed long enough for the watchdog to wrap, we're
way out of tolerable behavior. There's not much we can do because we
can't even tell what happened.

But in the case where the watchdog has not wrapped, I don't see a
major issue with trying to be a bit more robust in the face of just
slightly delayed timers.
(And yes, we can't really distinguish between slightly delayed and
watchdog-wrap-interval + slight delay, but in either case we can
probably skip disqualifying the clocksource as we know something seems
off)

thanks
-john

2021-10-12 05:06:34

[permalink] [raw]

Subject: Re: [External] Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Sat, Oct 9, 2021 at 2:02 AM yanghui <[email protected]> wrote:
>
>
>
> 在 2021/10/9 上午11:38, John Stultz 写道:
> > On Fri, Oct 8, 2021 at 8:22 PM yanghui <[email protected]> wrote:
> >> 在 2021/10/9 上午7:45, John Stultz 写道:
> >>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
> >>>>
> >>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
> >>>> Timer. But sometimes system is very busy and the Timer cannot be
> >>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
> >>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
> >>>> be enlarged. Then the current clocksource will be misjudged as
> >>>> unstable. So we add conditions to prevent the clocksource from
> >>>> being misjudged.
> >>>>
> >>>> Signed-off-by: yanghui <[email protected]>
> >>>> ---
> >>>> kernel/time/clocksource.c | 6 +++++-
> >>>> 1 file changed, 5 insertions(+), 1 deletion(-)
> >>>>
> >>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> >>>> index b8a14d2fb5ba..d535beadcbc8 100644
> >>>> --- a/kernel/time/clocksource.c
> >>>> +++ b/kernel/time/clocksource.c
> >>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
> >>>>
> >>>> /*
> >>>> * Interval: 0.5sec.
> >>>> + * MaxInterval: 1s.
> >>>> */
> >>>> #define WATCHDOG_INTERVAL (HZ >> 1)
> >>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> >>>>
> >>>> static void clocksource_watchdog_work(struct work_struct *work)
> >>>> {
> >>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
> >>>>
> >>>> /* Check the deviation from the watchdog clocksource. */
> >>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> >>>> - if (abs(cs_nsec - wd_nsec) > md) {
> >>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
> >>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
> >>>
> >>> Sorry, it's been awhile since I looked at this code, but why are you
> >>> bounding the clocksource delta here?
> >>> It seems like if the clocksource being watched was very wrong (with a
> >>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
> >>>
> >>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
> >>>
> >>> Bounding the watchdog interval on the check does seem reasonable.
> >>> Though one may want to keep track that if we are seeing too many of
> >>> these delayed watchdog checks we provide some feedback via dmesg.
> >>
> >> Yes, only to check watchdog delta is more reasonable.
> >> I think Only have dmesg is not enough, because if tsc was be misjudged
> >> as unstable then switch to hpet. And hpet is very expensive for
> >> performance, so if we want to switch to tsc the only way is to reboot
> >> the server. We need to prevent the switching of the clock source in
> >> case of misjudgment.
> >> Circumstances of misjudgment:
> >> if clocksource_watchdog is executed after 10sec, the value of wd_delta
> >> and cs_delta also be about 10sec, also the value of (cs_nsec- wd_nsec)
> >> will be magnified 20 times(10sec/0.5sec).The delta value is magnified.
> >
> > Yea, it might be worth calculating an error rate instead of assuming
> > the interval is fixed, but also just skipping the check may be
> > reasonable assuming timers aren't constantly being delayed (and it's
> > more of a transient state).
> >
> > At some point if the watchdog timer is delayed too much, the watchdog
> I mean the execution cycle of this function(static void
> clocksource_watchdog(struct timer_list *unused)) has been delayed.
>
> > hardware will fully wrap and one can no longer properly compare
> > intervals. That's why the timer length is chosen as such, so having
> > that timer delayed is really pushing the system into a potentially bad
> > state where other subtle problems are likely to crop up.
> >
> > So I do worry these watchdog robustness fixes are papering over a
> > problem, pushing expectations closer to the edge of how far the system
> > should tolerate bad behavior. Because at some point we'll fall off. :)
>
> Sorry,I don't seem to understand what you mean. Should I send your Patch
> v2 ?

Sending a v2 is usually a good step (persistence is key! :)

I'm sorry for being unclear in the above. I'm mostly just fretting
that the watchdog logic has inherent assumptions that the timers won't
be greatly delayed. Unfortunately the reality is that the timers may
be delayed. So we can try to add some robustness (as your patch does),
but at a certain point, the delays may exceed what the logic can
tolerate and produce correct behavior. I worry that by pushing the
robustness up to that limit, folks may not recognize the problematic
behavior (greatly delayed timers - possibly caused by drivers
disabling irqs for too long, or bad SMI logic, or long virtualization
pauses), and think the system is still working as designed, even
though its regularly exceeding the bounds of the assumptions in the
code. So without any feedback that something is wrong, those bounds
will continue to be pushed until things really break in a way we
cannot be robust about.

That's why I was suggesting adding some sort of printk warning when we
do see a number of delayed timers so that folks have some signal that
things are not as they are expected to be.

thanks
-john

2021-10-12 05:26:38

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

John Stultz wrote on 2021/10/12 12:52 下午:
> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
>>
>> hello
>>
>> John Stultz wrote on 2021/10/9 7:45:
>>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>>>
>>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>>>> Timer. But sometimes system is very busy and the Timer cannot be
>>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>>>> be enlarged. Then the current clocksource will be misjudged as
>>>> unstable. So we add conditions to prevent the clocksource from
>>>> being misjudged.
>>>>
>>>> Signed-off-by: yanghui <[email protected]>
>>>> ---
>>>> kernel/time/clocksource.c | 6 +++++-
>>>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>>>
>>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>>> index b8a14d2fb5ba..d535beadcbc8 100644
>>>> --- a/kernel/time/clocksource.c
>>>> +++ b/kernel/time/clocksource.c
>>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>>>
>>>> /*
>>>> * Interval: 0.5sec.
>>>> + * MaxInterval: 1s.
>>>> */
>>>> #define WATCHDOG_INTERVAL (HZ >> 1)
>>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>>>
>>>> static void clocksource_watchdog_work(struct work_struct *work)
>>>> {
>>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>>
>>>> /* Check the deviation from the watchdog clocksource. */
>>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>>> - if (abs(cs_nsec - wd_nsec) > md) {
>>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>>>
>>> Sorry, it's been awhile since I looked at this code, but why are you
>>> bounding the clocksource delta here?
>>> It seems like if the clocksource being watched was very wrong (with a
>>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>>>
>>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>>>
>>> Bounding the watchdog interval on the check does seem reasonable.
>>> Though one may want to keep track that if we are seeing too many of
>>> these delayed watchdog checks we provide some feedback via dmesg.
>>
>> For some fast timeout timers, such as acpi-timer, checking wd_nsec should not
>> make much sense, because when wacthdog is called, the timer may overflow many
>> times.
>
> Indeed. But in that case we can't tell which way is up. This is what I
> was fretting about when I said:
>> So I do worry these watchdog robustness fixes are papering over a
>> problem, pushing expectations closer to the edge of how far the system
>> should tolerate bad behavior. Because at some point we'll fall off. :)
>
> If the timer is delayed long enough for the watchdog to wrap, we're
> way out of tolerable behavior. There's not much we can do because we
> can't even tell what happened.
>
> But in the case where the watchdog has not wrapped, I don't see a
> major issue with trying to be a bit more robust in the face of just
> slightly delayed timers.
> (And yes, we can't really distinguish between slightly delayed and
> watchdog-wrap-interval + slight delay, but in either case we can
> probably skip disqualifying the clocksource as we know something seems
> off)

If we record the watchdog's start_time in clocksource_start_watchdog(), and then
when we verify cycles in clocksource_watchdog(), check whether the clocksource
watchdog is blocked. Due to MSB verification, if the blocked time is greater than
half of the watchdog timer max_cycles, then we can safely ignore the current
verification? Do you think this idea is okay?

> thanks
> -john
>

2021-10-12 05:33:23

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> John Stultz wrote on 2021/10/12 12:52 下午:
> > On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> >>
> >> hello
> >>
> >> John Stultz wrote on 2021/10/9 7:45:
> >>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
> >>>>
> >>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
> >>>> Timer. But sometimes system is very busy and the Timer cannot be
> >>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
> >>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
> >>>> be enlarged. Then the current clocksource will be misjudged as
> >>>> unstable. So we add conditions to prevent the clocksource from
> >>>> being misjudged.
> >>>>
> >>>> Signed-off-by: yanghui <[email protected]>
> >>>> ---
> >>>> kernel/time/clocksource.c | 6 +++++-
> >>>> 1 file changed, 5 insertions(+), 1 deletion(-)
> >>>>
> >>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> >>>> index b8a14d2fb5ba..d535beadcbc8 100644
> >>>> --- a/kernel/time/clocksource.c
> >>>> +++ b/kernel/time/clocksource.c
> >>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
> >>>>
> >>>> /*
> >>>> * Interval: 0.5sec.
> >>>> + * MaxInterval: 1s.
> >>>> */
> >>>> #define WATCHDOG_INTERVAL (HZ >> 1)
> >>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> >>>>
> >>>> static void clocksource_watchdog_work(struct work_struct *work)
> >>>> {
> >>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
> >>>>
> >>>> /* Check the deviation from the watchdog clocksource. */
> >>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> >>>> - if (abs(cs_nsec - wd_nsec) > md) {
> >>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
> >>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
> >>>
> >>> Sorry, it's been awhile since I looked at this code, but why are you
> >>> bounding the clocksource delta here?
> >>> It seems like if the clocksource being watched was very wrong (with a
> >>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
> >>>
> >>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
> >>>
> >>> Bounding the watchdog interval on the check does seem reasonable.
> >>> Though one may want to keep track that if we are seeing too many of
> >>> these delayed watchdog checks we provide some feedback via dmesg.
> >>
> >> For some fast timeout timers, such as acpi-timer, checking wd_nsec should not
> >> make much sense, because when wacthdog is called, the timer may overflow many
> >> times.
> >
> > Indeed. But in that case we can't tell which way is up. This is what I
> > was fretting about when I said:
> >> So I do worry these watchdog robustness fixes are papering over a
> >> problem, pushing expectations closer to the edge of how far the system
> >> should tolerate bad behavior. Because at some point we'll fall off. :)
> >
> > If the timer is delayed long enough for the watchdog to wrap, we're
> > way out of tolerable behavior. There's not much we can do because we
> > can't even tell what happened.
> >
> > But in the case where the watchdog has not wrapped, I don't see a
> > major issue with trying to be a bit more robust in the face of just
> > slightly delayed timers.
> > (And yes, we can't really distinguish between slightly delayed and
> > watchdog-wrap-interval + slight delay, but in either case we can
> > probably skip disqualifying the clocksource as we know something seems
> > off)
>
> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> half of the watchdog timer max_cycles, then we can safely ignore the current
> verification? Do you think this idea is okay?

I can't say I totally understand the idea. Maybe could you clarify with a patch?

thanks
-john

2021-10-12 08:09:03

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

John Stultz wrote on 2021/10/12 13:29:
> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
>> John Stultz wrote on 2021/10/12 12:52 下午:
>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
>>>>
>>>> hello
>>>>
>>>> John Stultz wrote on 2021/10/9 7:45:
>>>>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>>>>>
>>>>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>>>>>> Timer. But sometimes system is very busy and the Timer cannot be
>>>>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>>>>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>>>>>> be enlarged. Then the current clocksource will be misjudged as
>>>>>> unstable. So we add conditions to prevent the clocksource from
>>>>>> being misjudged.
>>>>>>
>>>>>> Signed-off-by: yanghui <[email protected]>
>>>>>> ---
>>>>>> kernel/time/clocksource.c | 6 +++++-
>>>>>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>>>>>
>>>>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>>>>> index b8a14d2fb5ba..d535beadcbc8 100644
>>>>>> --- a/kernel/time/clocksource.c
>>>>>> +++ b/kernel/time/clocksource.c
>>>>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>>>>>
>>>>>> /*
>>>>>> * Interval: 0.5sec.
>>>>>> + * MaxInterval: 1s.
>>>>>> */
>>>>>> #define WATCHDOG_INTERVAL (HZ >> 1)
>>>>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>>>>>
>>>>>> static void clocksource_watchdog_work(struct work_struct *work)
>>>>>> {
>>>>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>>>>
>>>>>> /* Check the deviation from the watchdog clocksource. */
>>>>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>>>>> - if (abs(cs_nsec - wd_nsec) > md) {
>>>>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>>>>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>>>>>
>>>>> Sorry, it's been awhile since I looked at this code, but why are you
>>>>> bounding the clocksource delta here?
>>>>> It seems like if the clocksource being watched was very wrong (with a
>>>>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>>>>>
>>>>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>>>>>
>>>>> Bounding the watchdog interval on the check does seem reasonable.
>>>>> Though one may want to keep track that if we are seeing too many of
>>>>> these delayed watchdog checks we provide some feedback via dmesg.
>>>>
>>>> For some fast timeout timers, such as acpi-timer, checking wd_nsec should not
>>>> make much sense, because when wacthdog is called, the timer may overflow many
>>>> times.
>>>
>>> Indeed. But in that case we can't tell which way is up. This is what I
>>> was fretting about when I said:
>>>> So I do worry these watchdog robustness fixes are papering over a
>>>> problem, pushing expectations closer to the edge of how far the system
>>>> should tolerate bad behavior. Because at some point we'll fall off. :)
>>>
>>> If the timer is delayed long enough for the watchdog to wrap, we're
>>> way out of tolerable behavior. There's not much we can do because we
>>> can't even tell what happened.
>>>
>>> But in the case where the watchdog has not wrapped, I don't see a
>>> major issue with trying to be a bit more robust in the face of just
>>> slightly delayed timers.
>>> (And yes, we can't really distinguish between slightly delayed and
>>> watchdog-wrap-interval + slight delay, but in either case we can
>>> probably skip disqualifying the clocksource as we know something seems
>>> off)
>>
>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
>> half of the watchdog timer max_cycles, then we can safely ignore the current
>> verification? Do you think this idea is okay?
>
> I can't say I totally understand the idea. Maybe could you clarify with a patch?
>

Sorry, it looks almost as follows:

diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
index b8a14d2..87f3b67 100644
--- a/kernel/time/clocksource.c
+++ b/kernel/time/clocksource.c
@@ -119,6 +119,7 @@
static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
static DEFINE_SPINLOCK(watchdog_lock);
static int watchdog_running;
+static unsigned long watchdog_start_time;
static atomic_t watchdog_reset_pending;

static inline void clocksource_watchdog_lock(unsigned long *flags)
@@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
int next_cpu, reset_pending;
int64_t wd_nsec, cs_nsec;
struct clocksource *cs;
+ unsigned long max_jiffies;
u32 md;

spin_lock(&watchdog_lock);
@@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
if (atomic_read(&watchdog_reset_pending))
continue;

+ max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
+ if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
+ continue;
+
/* Check the deviation from the watchdog clocksource. */
md = cs->uncertainty_margin + watchdog->uncertainty_margin;
if (abs(cs_nsec - wd_nsec) > md) {
@@ -474,6 +480,7 @@ static void clocksource_watchdog(struct timer_list *unused)
* pair clocksource_stop_watchdog() clocksource_start_watchdog().
*/
if (!timer_pending(&watchdog_timer)) {
+ watchdog_start_time = jiffies;
watchdog_timer.expires += WATCHDOG_INTERVAL;
add_timer_on(&watchdog_timer, next_cpu);
}
@@ -488,6 +495,7 @@ static inline void clocksource_start_watchdog(void)
timer_setup(&watchdog_timer, clocksource_watchdog, 0);
watchdog_timer.expires = jiffies + WATCHDOG_INTERVAL;
add_timer_on(&watchdog_timer, cpumask_first(cpu_online_mask));
+ watchdog_start_time = jiffies;
watchdog_running = 1;
}

> thanks
> -john
>

2021-10-14 07:07:23

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

在 2021/10/12 下午4:06, brookxu 写道:
>
>
> John Stultz wrote on 2021/10/12 13:29:
>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
>>> John Stultz wrote on 2021/10/12 12:52 下午:
>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
>>>>>
>>>>> hello
>>>>>
>>>>> John Stultz wrote on 2021/10/9 7:45:
>>>>>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>>>>>>
>>>>>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>>>>>>> Timer. But sometimes system is very busy and the Timer cannot be
>>>>>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>>>>>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>>>>>>> be enlarged. Then the current clocksource will be misjudged as
>>>>>>> unstable. So we add conditions to prevent the clocksource from
>>>>>>> being misjudged.
>>>>>>>
>>>>>>> Signed-off-by: yanghui <[email protected]>
>>>>>>> ---
>>>>>>> kernel/time/clocksource.c | 6 +++++-
>>>>>>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>>>>>>
>>>>>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>>>>>> index b8a14d2fb5ba..d535beadcbc8 100644
>>>>>>> --- a/kernel/time/clocksource.c
>>>>>>> +++ b/kernel/time/clocksource.c
>>>>>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>>>>>>
>>>>>>> /*
>>>>>>> * Interval: 0.5sec.
>>>>>>> + * MaxInterval: 1s.
>>>>>>> */
>>>>>>> #define WATCHDOG_INTERVAL (HZ >> 1)
>>>>>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>>>>>>
>>>>>>> static void clocksource_watchdog_work(struct work_struct *work)
>>>>>>> {
>>>>>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>>>>>
>>>>>>> /* Check the deviation from the watchdog clocksource. */
>>>>>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>>>>>> - if (abs(cs_nsec - wd_nsec) > md) {
>>>>>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>>>>>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>>>>>>
>>>>>> Sorry, it's been awhile since I looked at this code, but why are you
>>>>>> bounding the clocksource delta here?
>>>>>> It seems like if the clocksource being watched was very wrong (with a
>>>>>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>>>>>>
>>>>>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>>>>>>
>>>>>> Bounding the watchdog interval on the check does seem reasonable.
>>>>>> Though one may want to keep track that if we are seeing too many of
>>>>>> these delayed watchdog checks we provide some feedback via dmesg.
>>>>>
>>>>> For some fast timeout timers, such as acpi-timer, checking wd_nsec should not
>>>>> make much sense, because when wacthdog is called, the timer may overflow many
>>>>> times.
>>>>
>>>> Indeed. But in that case we can't tell which way is up. This is what I
>>>> was fretting about when I said:
>>>>> So I do worry these watchdog robustness fixes are papering over a
>>>>> problem, pushing expectations closer to the edge of how far the system
>>>>> should tolerate bad behavior. Because at some point we'll fall off. :)
>>>>
>>>> If the timer is delayed long enough for the watchdog to wrap, we're
>>>> way out of tolerable behavior. There's not much we can do because we
>>>> can't even tell what happened.
>>>>
>>>> But in the case where the watchdog has not wrapped, I don't see a
>>>> major issue with trying to be a bit more robust in the face of just
>>>> slightly delayed timers.
>>>> (And yes, we can't really distinguish between slightly delayed and
>>>> watchdog-wrap-interval + slight delay, but in either case we can
>>>> probably skip disqualifying the clocksource as we know something seems
>>>> off)
>>>
>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
>>> half of the watchdog timer max_cycles, then we can safely ignore the current
>>> verification? Do you think this idea is okay?
>>
>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
>>
>
> Sorry, it looks almost as follows:
>
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index b8a14d2..87f3b67 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -119,6 +119,7 @@
> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> static DEFINE_SPINLOCK(watchdog_lock);
> static int watchdog_running;
> +static unsigned long watchdog_start_time;
> static atomic_t watchdog_reset_pending;
>
> static inline void clocksource_watchdog_lock(unsigned long *flags)
> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> int next_cpu, reset_pending;
> int64_t wd_nsec, cs_nsec;
> struct clocksource *cs;
> + unsigned long max_jiffies;
> u32 md;
>
> spin_lock(&watchdog_lock);
> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> if (atomic_read(&watchdog_reset_pending))
> continue;
>
> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> + continue;
> +
> /* Check the deviation from the watchdog clocksource. */
> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> if (abs(cs_nsec - wd_nsec) > md) {
> @@ -474,6 +480,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> * pair clocksource_stop_watchdog() clocksource_start_watchdog().
> */
> if (!timer_pending(&watchdog_timer)) {
> + watchdog_start_time = jiffies;
> watchdog_timer.expires += WATCHDOG_INTERVAL;
> add_timer_on(&watchdog_timer, next_cpu);
> }
> @@ -488,6 +495,7 @@ static inline void clocksource_start_watchdog(void)
> timer_setup(&watchdog_timer, clocksource_watchdog, 0);
> watchdog_timer.expires = jiffies + WATCHDOG_INTERVAL;
> add_timer_on(&watchdog_timer, cpumask_first(cpu_online_mask));
> + watchdog_start_time = jiffies;
> watchdog_running = 1;
> }
>
>
>> thanks
>> -john
>>

It looks good to me.
thanks.

2021-10-15 13:05:56

[permalink] [raw]

Subject: [PATCH] Clocksource: Avoid misjudgment of clocksource

在 2021/10/14 下午3:03, yanghui 写道:
>
>
> 在 2021/10/12 下午4:06, brookxu 写道:
>>
>>
>> John Stultz wrote on 2021/10/12 13:29:
>>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
>>>> John Stultz wrote on 2021/10/12 12:52 下午:
>>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
>>>>>>
>>>>>> hello
>>>>>>
>>>>>> John Stultz wrote on 2021/10/9 7:45:
>>>>>>> On Fri, Oct 8, 2021 at 1:03 AM yanghui
>>>>>>> <[email protected]> wrote:
>>>>>>>>
>>>>>>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>>>>>>>> Timer. But sometimes system is very busy and the Timer cannot be
>>>>>>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>>>>>>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>>>>>>>> be enlarged. Then the current clocksource will be misjudged as
>>>>>>>> unstable. So we add conditions to prevent the clocksource from
>>>>>>>> being misjudged.
>>>>>>>>
>>>>>>>> Signed-off-by: yanghui <[email protected]>
>>>>>>>> ---
>>>>>>>> kernel/time/clocksource.c | 6 +++++-
>>>>>>>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>>>>>>>
>>>>>>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>>>>>>> index b8a14d2fb5ba..d535beadcbc8 100644
>>>>>>>> --- a/kernel/time/clocksource.c
>>>>>>>> +++ b/kernel/time/clocksource.c
>>>>>>>> @@ -136,8 +136,10 @@ static void
>>>>>>>> __clocksource_change_rating(struct clocksource *cs, int rating);
>>>>>>>>
>>>>>>>> /*
>>>>>>>>    * Interval: 0.5sec.
>>>>>>>> + * MaxInterval: 1s.
>>>>>>>>    */
>>>>>>>> #define WATCHDOG_INTERVAL (HZ >> 1)
>>>>>>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>>>>>>>
>>>>>>>> static void clocksource_watchdog_work(struct work_struct *work)
>>>>>>>> {
>>>>>>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct
>>>>>>>> timer_list *unused)
>>>>>>>>
>>>>>>>>                  /* Check the deviation from the watchdog
>>>>>>>> clocksource. */
>>>>>>>>                  md = cs->uncertainty_margin +
>>>>>>>> watchdog->uncertainty_margin;
>>>>>>>> -               if (abs(cs_nsec - wd_nsec) > md) {
>>>>>>>> +               if ((abs(cs_nsec - wd_nsec) > md) &&
>>>>>>>> +                       cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>>>>>>>
>>>>>>> Sorry, it's been awhile since I looked at this code, but why are you
>>>>>>> bounding the clocksource delta here?
>>>>>>> It seems like if the clocksource being watched was very wrong
>>>>>>> (with a
>>>>>>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>>>>>>>
>>>>>>>> +                       wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>>>>>>>
>>>>>>> Bounding the watchdog interval on the check does seem reasonable.
>>>>>>> Though one may want to keep track that if we are seeing too many of
>>>>>>> these delayed watchdog checks we provide some feedback via dmesg.
>>>>>>
>>>>>> For some fast timeout timers, such as acpi-timer, checking wd_nsec
>>>>>> should not
>>>>>> make much sense, because when wacthdog is called, the timer may
>>>>>> overflow many
>>>>>> times.
>>>>>
>>>>> Indeed. But in that case we can't tell which way is up. This is what I
>>>>> was fretting about when I said:
>>>>>> So I do worry these watchdog robustness fixes are papering over a
>>>>>> problem, pushing expectations closer to the edge of how far the
>>>>>> system
>>>>>> should tolerate bad behavior. Because at some point we'll fall
>>>>>> off. :)
>>>>>
>>>>> If the timer is delayed long enough for the watchdog to wrap, we're
>>>>> way out of tolerable behavior. There's not much we can do because we
>>>>> can't even tell what happened.
>>>>>
>>>>> But in the case where the watchdog has not wrapped, I don't see a
>>>>> major issue with trying to be a bit more robust in the face of just
>>>>> slightly delayed timers.
>>>>> (And yes, we can't really distinguish between slightly delayed and
>>>>> watchdog-wrap-interval + slight delay, but in either case we can
>>>>> probably skip disqualifying the clocksource as we know something seems
>>>>> off)
>>>>
>>>> If we record the watchdog's start_time in
>>>> clocksource_start_watchdog(), and then
>>>> when we verify cycles in clocksource_watchdog(), check whether the
>>>> clocksource
>>>> watchdog is blocked. Due to MSB verification, if the blocked time is
>>>> greater than
>>>> half of the watchdog timer max_cycles, then we can safely ignore the
>>>> current
>>>> verification? Do you think this idea is okay?
>>>
>>> I can't say I totally understand the idea. Maybe could you clarify
>>> with a patch?
>>>
>>
>> Sorry, it looks almost as follows:
>>
>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>> index b8a14d2..87f3b67 100644
>> --- a/kernel/time/clocksource.c
>> +++ b/kernel/time/clocksource.c
>> @@ -119,6 +119,7 @@
>> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
>> static DEFINE_SPINLOCK(watchdog_lock);
>> static int watchdog_running;
>> +static unsigned long watchdog_start_time;
>> static atomic_t watchdog_reset_pending;
>> static inline void clocksource_watchdog_lock(unsigned long *flags)
>> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list
>> *unused)
>>       int next_cpu, reset_pending;
>>       int64_t wd_nsec, cs_nsec;
>>       struct clocksource *cs;
>> +    unsigned long max_jiffies;
>>       u32 md;
>>       spin_lock(&watchdog_lock);
>> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct
>> timer_list *unused)
>>           if (atomic_read(&watchdog_reset_pending))
>>               continue;
>> +        max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
>> +        if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
>> +            continue;
>> +

Hi John:
What do you think of this suggest？If the interval between two
executions of the function clocksource_watchdog() exceeds max_idle_ns.
We think the current judement is unreasonable,so we skip this judgment.

>>           /* Check the deviation from the watchdog clocksource. */
>>           md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>           if (abs(cs_nsec - wd_nsec) > md) {
>> @@ -474,6 +480,7 @@ static void clocksource_watchdog(struct timer_list
>> *unused)
>>        * pair clocksource_stop_watchdog() clocksource_start_watchdog().
>>        */
>>       if (!timer_pending(&watchdog_timer)) {
>> +        watchdog_start_time = jiffies;
>>           watchdog_timer.expires += WATCHDOG_INTERVAL;
>>           add_timer_on(&watchdog_timer, next_cpu);
>>       }
>> @@ -488,6 +495,7 @@ static inline void clocksource_start_watchdog(void)
>>       timer_setup(&watchdog_timer, clocksource_watchdog, 0);
>>       watchdog_timer.expires = jiffies + WATCHDOG_INTERVAL;
>>       add_timer_on(&watchdog_timer, cpumask_first(cpu_online_mask));
>> +    watchdog_start_time = jiffies;
>>       watchdog_running = 1;
>> }
>>
>>
>>> thanks
>>> -john
>>>
>
> It looks good to me.
> thanks.

2021-10-15 13:24:53

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

Hello

>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>> index b8a14d2..87f3b67 100644
>>> --- a/kernel/time/clocksource.c
>>> +++ b/kernel/time/clocksource.c
>>> @@ -119,6 +119,7 @@
>>> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
>>> static DEFINE_SPINLOCK(watchdog_lock);
>>> static int watchdog_running;
>>> +static unsigned long watchdog_start_time;
>>> static atomic_t watchdog_reset_pending;
>>> static inline void clocksource_watchdog_lock(unsigned long *flags)
>>> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>       int next_cpu, reset_pending;
>>>       int64_t wd_nsec, cs_nsec;
>>>       struct clocksource *cs;
>>> +    unsigned long max_jiffies;
>>>       u32 md;
>>>       spin_lock(&watchdog_lock);
>>> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>           if (atomic_read(&watchdog_reset_pending))
>>>               continue;
>>> +        max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
>>> +        if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
>>> +            continue;
>>> +
>
> Hi John:
> What do you think of this suggest？If the interval between two executions of the function clocksource_watchdog() exceeds max_idle_ns. We think the current judement is unreasonable,so we skip this judgment.

I feel that there are still some things that need to be discussed. This
solution may still fail in some scenarios. Assume that tick_do_timer_cpu
is CPU1 and clocksource watchdog is CPU2. At a certain point in time, CPU1
updates jiffies, and then the interrupt is closed for some reason, then
jiffies will not be updated. At the same time, the clocksource watchdog of
CPU2 is activated, and still delayed for a period of time due to high load.
Since the jiffies is not updated, this judgment should fail at this time.
But I think it might be necessary to troubleshoot other problems, because
the interrupt should not closed for a long time. How do you think about
this scene.

Thanks.
>>>           /* Check the deviation from the watchdog clocksource. */
>>>           md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>>           if (abs(cs_nsec - wd_nsec) > md) {
>>> @@ -474,6 +480,7 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>        * pair clocksource_stop_watchdog() clocksource_start_watchdog().
>>>        */
>>>       if (!timer_pending(&watchdog_timer)) {
>>> +        watchdog_start_time = jiffies;
>>>           watchdog_timer.expires += WATCHDOG_INTERVAL;
>>>           add_timer_on(&watchdog_timer, next_cpu);
>>>       }
>>> @@ -488,6 +495,7 @@ static inline void clocksource_start_watchdog(void)
>>>       timer_setup(&watchdog_timer, clocksource_watchdog, 0);
>>>       watchdog_timer.expires = jiffies + WATCHDOG_INTERVAL;
>>>       add_timer_on(&watchdog_timer, cpumask_first(cpu_online_mask));
>>> +    watchdog_start_time = jiffies;
>>>       watchdog_running = 1;
>>> }
>>>
>>>
>>>> thanks
>>>> -john
>>>>
>>
>> It looks good to me.
>> thanks.
>

2021-10-18 10:46:03

[permalink] [raw]

Subject: [PATCH] Clocksource: Avoid misjudgment of clocksource

在 2021/10/12 下午1:02, John Stultz 写道:
> On Sat, Oct 9, 2021 at 2:02 AM yanghui <[email protected]> wrote:
>>
>>
>>
>> 在 2021/10/9 上午11:38, John Stultz 写道:
>>> On Fri, Oct 8, 2021 at 8:22 PM yanghui <[email protected]> wrote:
>>>> 在 2021/10/9 上午7:45, John Stultz 写道:
>>>>> On Fri, Oct 8, 2021 at 1:03 AM yanghui <[email protected]> wrote:
>>>>>>
>>>>>> clocksource_watchdog is executed every WATCHDOG_INTERVAL(0.5s) by
>>>>>> Timer. But sometimes system is very busy and the Timer cannot be
>>>>>> executed in 0.5sec. For example,if clocksource_watchdog be executed
>>>>>> after 10sec, the calculated value of abs(cs_nsec - wd_nsec) will
>>>>>> be enlarged. Then the current clocksource will be misjudged as
>>>>>> unstable. So we add conditions to prevent the clocksource from
>>>>>> being misjudged.
>>>>>>
>>>>>> Signed-off-by: yanghui <[email protected]>
>>>>>> ---
>>>>>> kernel/time/clocksource.c | 6 +++++-
>>>>>> 1 file changed, 5 insertions(+), 1 deletion(-)
>>>>>>
>>>>>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>>>>>> index b8a14d2fb5ba..d535beadcbc8 100644
>>>>>> --- a/kernel/time/clocksource.c
>>>>>> +++ b/kernel/time/clocksource.c
>>>>>> @@ -136,8 +136,10 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>>>>>
>>>>>> /*
>>>>>> * Interval: 0.5sec.
>>>>>> + * MaxInterval: 1s.
>>>>>> */
>>>>>> #define WATCHDOG_INTERVAL (HZ >> 1)
>>>>>> +#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
>>>>>>
>>>>>> static void clocksource_watchdog_work(struct work_struct *work)
>>>>>> {
>>>>>> @@ -404,7 +406,9 @@ static void clocksource_watchdog(struct timer_list *unused)
>>>>>>
>>>>>> /* Check the deviation from the watchdog clocksource. */
>>>>>> md = cs->uncertainty_margin + watchdog->uncertainty_margin;
>>>>>> - if (abs(cs_nsec - wd_nsec) > md) {
>>>>>> + if ((abs(cs_nsec - wd_nsec) > md) &&
>>>>>> + cs_nsec < WATCHDOG_MAX_INTERVAL_NS &&
>>>>>
>>>>> Sorry, it's been awhile since I looked at this code, but why are you
>>>>> bounding the clocksource delta here?
>>>>> It seems like if the clocksource being watched was very wrong (with a
>>>>> delta larger than the MAX_INTERVAL_NS), we'd want to throw it out.
>>>>>
>>>>>> + wd_nsec < WATCHDOG_MAX_INTERVAL_NS) {
>>>>>
>>>>> Bounding the watchdog interval on the check does seem reasonable.
>>>>> Though one may want to keep track that if we are seeing too many of
>>>>> these delayed watchdog checks we provide some feedback via dmesg.
>>>>
>>>> Yes, only to check watchdog delta is more reasonable.
>>>> I think Only have dmesg is not enough, because if tsc was be misjudged
>>>> as unstable then switch to hpet. And hpet is very expensive for
>>>> performance, so if we want to switch to tsc the only way is to reboot
>>>> the server. We need to prevent the switching of the clock source in
>>>> case of misjudgment.
>>>> Circumstances of misjudgment:
>>>> if clocksource_watchdog is executed after 10sec, the value of wd_delta
>>>> and cs_delta also be about 10sec, also the value of (cs_nsec- wd_nsec)
>>>> will be magnified 20 times(10sec/0.5sec).The delta value is magnified.
>>>
>>> Yea, it might be worth calculating an error rate instead of assuming
>>> the interval is fixed, but also just skipping the check may be
>>> reasonable assuming timers aren't constantly being delayed (and it's
>>> more of a transient state).
>>>
>>> At some point if the watchdog timer is delayed too much, the watchdog
>> I mean the execution cycle of this function(static void
>> clocksource_watchdog(struct timer_list *unused)) has been delayed.
>>
>>> hardware will fully wrap and one can no longer properly compare
>>> intervals. That's why the timer length is chosen as such, so having
>>> that timer delayed is really pushing the system into a potentially bad
>>> state where other subtle problems are likely to crop up.
>>>
>>> So I do worry these watchdog robustness fixes are papering over a
>>> problem, pushing expectations closer to the edge of how far the system
>>> should tolerate bad behavior. Because at some point we'll fall off. :)
>>
>> Sorry,I don't seem to understand what you mean. Should I send your Patch
>> v2 ?
>
> Sending a v2 is usually a good step (persistence is key! :)
>
> I'm sorry for being unclear in the above. I'm mostly just fretting
> that the watchdog logic has inherent assumptions that the timers won't
> be greatly delayed. Unfortunately the reality is that the timers may
> be delayed. So we can try to add some robustness (as your patch does),
> but at a certain point, the delays may exceed what the logic can
> tolerate and produce correct behavior. I worry that by pushing the
> robustness up to that limit, folks may not recognize the problematic
> behavior (greatly delayed timers - possibly caused by drivers
> disabling irqs for too long, or bad SMI logic, or long virtualization
> pauses), and think the system is still working as designed, even

I think we can increase the value of WATCHDOG_MAX_INTERVAL_NS up to
20sec(soft lockup time) or more longer. So we can filter those timer
delays caused by non-softlockup as your said(drivers disabling irq, bad
SMI logic ...).
I think this method can solve the problem that the softlock is
too long and the clocksource is incorrectly switched, resulting
in performance degradation.
> though its regularly exceeding the bounds of the assumptions in the
> code. So without any feedback that something is wrong, those bounds
> will continue to be pushed until things really break in a way we
> cannot be robust about.
>
> That's why I was suggesting adding some sort of printk warning when we
> do see a number of delayed timers so that folks have some signal that
> things are not as they are expected to be.
>
> thanks
> -john
>

2021-10-18 16:19:31

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> John Stultz wrote on 2021/10/12 13:29:
> > On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> >> John Stultz wrote on 2021/10/12 12:52 下午:
> >>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> >> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> >> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> >> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> >> half of the watchdog timer max_cycles, then we can safely ignore the current
> >> verification? Do you think this idea is okay?
> >
> > I can't say I totally understand the idea. Maybe could you clarify with a patch?
> >
>
> Sorry, it looks almost as follows:
>
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index b8a14d2..87f3b67 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -119,6 +119,7 @@
> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> static DEFINE_SPINLOCK(watchdog_lock);
> static int watchdog_running;
> +static unsigned long watchdog_start_time;
> static atomic_t watchdog_reset_pending;
>
> static inline void clocksource_watchdog_lock(unsigned long *flags)
> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> int next_cpu, reset_pending;
> int64_t wd_nsec, cs_nsec;
> struct clocksource *cs;
> + unsigned long max_jiffies;
> u32 md;
>
> spin_lock(&watchdog_lock);
> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> if (atomic_read(&watchdog_reset_pending))
> continue;
>
> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> + continue;
> +

Sorry, what is the benefit of using jiffies here? Jiffies are
updated by counting the number of tick intervals on the current
clocksource.

This seems like circular logic, where we're trying to judge the
current clocksource by using something we derived from the current
clocksource.
That's why the watchdog clocksource is important, as it's supposed to
be a separate counter that is more reliable (but likely slower) then
the preferred clocksource.

So I'm not really sure how this helps.

The earlier patch by yanghui at least used the watchdog interval to
decide if the watchdog timer had expired late. Which seemed
reasonable, but I thought it might be helpful to add some sort of a
counter so if the case is happening repeatedly (timers constantly
being delayed) we have a better signal that the watchdog and current
clocksource are out of sync. Because again, timers are fired based on
the current clocksource. So constant delays likely mean things are
wrong.

thanks
-john

thanks
-john

2021-10-19 04:17:04

[permalink] [raw]

Subject: [PATCH] Clocksource: Avoid misjudgment of clocksource

在 2021/10/19 上午12:14, John Stultz 写道:
> On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
>> John Stultz wrote on 2021/10/12 13:29:
>>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
>>>> John Stultz wrote on 2021/10/12 12:52 下午:
>>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
>>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
>>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
>>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
>>>> half of the watchdog timer max_cycles, then we can safely ignore the current
>>>> verification? Do you think this idea is okay?
>>>
>>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
>>>
>>
>> Sorry, it looks almost as follows:
>>
>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>> index b8a14d2..87f3b67 100644
>> --- a/kernel/time/clocksource.c
>> +++ b/kernel/time/clocksource.c
>> @@ -119,6 +119,7 @@
>> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
>> static DEFINE_SPINLOCK(watchdog_lock);
>> static int watchdog_running;
>> +static unsigned long watchdog_start_time;
>> static atomic_t watchdog_reset_pending;
>>
>> static inline void clocksource_watchdog_lock(unsigned long *flags)
>> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
>> int next_cpu, reset_pending;
>> int64_t wd_nsec, cs_nsec;
>> struct clocksource *cs;
>> + unsigned long max_jiffies;
>> u32 md;
>>
>> spin_lock(&watchdog_lock);
>> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
>> if (atomic_read(&watchdog_reset_pending))
>> continue;
>>
>> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
>> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
>> + continue;
>> +
>
> Sorry, what is the benefit of using jiffies here? Jiffies are
> updated by counting the number of tick intervals on the current
> clocksource.
>
> This seems like circular logic, where we're trying to judge the
> current clocksource by using something we derived from the current
> clocksource.
> That's why the watchdog clocksource is important, as it's supposed to
> be a separate counter that is more reliable (but likely slower) then
> the preferred clocksource.
>
> So I'm not really sure how this helps.
>
> The earlier patch by yanghui at least used the watchdog interval to
> decide if the watchdog timer had expired late. Which seemed
> reasonable, but I thought it might be helpful to add some sort of a
> counter so if the case is happening repeatedly (timers constantly
> being delayed) we have a better signal that the watchdog and current
> clocksource are out of sync. Because again, timers are fired based on

I think only have a signal ls not enough. we need to prevent
clocksource from being incorrectly switched.

The Timer callback function clocksource_watchdog() is executed in the
context of softirq(run_timer_softirq()). So if softirq is disabled for
long time(One situation is long time softlockup), clocksource_watchdog()
will be delay executed.
> the current clocksource. So constant delays likely mean things are
> wrong.
> > thanks
> -john
>
> thanks
> -john
>
I think it will be better to add this to my patch:
/*
* Interval: 0.5sec.
- * MaxInterval: 1s.
+ * MaxInterval: 20s.
*/
#define WATCHDOG_INTERVAL (HZ >> 1)
-#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
+#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)

thanks

2021-10-19 05:05:25

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> 在 2021/10/19 上午12:14, John Stultz 写道:
> > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> >> John Stultz wrote on 2021/10/12 13:29:
> >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> >>>> verification? Do you think this idea is okay?
> >>>
> >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> >>>
> >>
> >> Sorry, it looks almost as follows:
> >>
> >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> >> index b8a14d2..87f3b67 100644
> >> --- a/kernel/time/clocksource.c
> >> +++ b/kernel/time/clocksource.c
> >> @@ -119,6 +119,7 @@
> >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> >> static DEFINE_SPINLOCK(watchdog_lock);
> >> static int watchdog_running;
> >> +static unsigned long watchdog_start_time;
> >> static atomic_t watchdog_reset_pending;
> >>
> >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> >> int next_cpu, reset_pending;
> >> int64_t wd_nsec, cs_nsec;
> >> struct clocksource *cs;
> >> + unsigned long max_jiffies;
> >> u32 md;
> >>
> >> spin_lock(&watchdog_lock);
> >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> >> if (atomic_read(&watchdog_reset_pending))
> >> continue;
> >>
> >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> >> + continue;
> >> +
> >
> > Sorry, what is the benefit of using jiffies here? Jiffies are
> > updated by counting the number of tick intervals on the current
> > clocksource.
> >
> > This seems like circular logic, where we're trying to judge the
> > current clocksource by using something we derived from the current
> > clocksource.
> > That's why the watchdog clocksource is important, as it's supposed to
> > be a separate counter that is more reliable (but likely slower) then
> > the preferred clocksource.
> >
> > So I'm not really sure how this helps.
> >
> > The earlier patch by yanghui at least used the watchdog interval to
> > decide if the watchdog timer had expired late. Which seemed
> > reasonable, but I thought it might be helpful to add some sort of a
> > counter so if the case is happening repeatedly (timers constantly
> > being delayed) we have a better signal that the watchdog and current
> > clocksource are out of sync. Because again, timers are fired based on
>
> I think only have a signal ls not enough. we need to prevent
> clocksource from being incorrectly switched.

Right, but we also have to ensure that we also properly disqualify
clocksources that are misbehaving.

In the case that the current clocksource is running very slow (imagine
old TSCs that lowered freq with cpufreq), then system time slows down,
so timers fire late.
So it would constantly seem like the irqs are being delayed, so with
your logic we would not disqualify a clearly malfunctioning
clocksource..

> The Timer callback function clocksource_watchdog() is executed in the
> context of softirq(run_timer_softirq()). So if softirq is disabled for
> long time(One situation is long time softlockup), clocksource_watchdog()
> will be delay executed.

Yes. The reality is that timers are often spuriously delayed. We don't
want a short burst of timer misbehavior to disqualify a good
clocksource.

But the problem is that this situation and the one above (with the
freq changing TSC), will look exactly the same.

So having a situation where if the watchdog clocksource thinks too
much time has passed between watchdog timers, we can skip judgement,
assuming its a spurious delay. But I think we need to keep a counter
so that if this happens 3-5 times in a row, we stop ignoring the
misbehavior and judge the current clocksource, as it may be running
slowly.

> >
> I think it will be better to add this to my patch:
> /*
> * Interval: 0.5sec.
> - * MaxInterval: 1s.
> + * MaxInterval: 20s.
> */
> #define WATCHDOG_INTERVAL (HZ >> 1)
> -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
>

Some watchdog counters wrap within 20 seconds, so I don't think this
is a good idea.

The other proposal to calculate the error rate, rather than a fixed
error boundary might be useful too, as if the current clocksource and
watchdog are close, a long timer delay won't disqualify them if we
scale the error bounds to be within an given error rate.

thanks
-john

2021-10-20 10:11:30

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
>
> On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > >> John Stultz wrote on 2021/10/12 13:29:
> > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > >>>> verification? Do you think this idea is okay?
> > >>>
> > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > >>>
> > >>
> > >> Sorry, it looks almost as follows:
> > >>
> > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > >> index b8a14d2..87f3b67 100644
> > >> --- a/kernel/time/clocksource.c
> > >> +++ b/kernel/time/clocksource.c
> > >> @@ -119,6 +119,7 @@
> > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > >> static DEFINE_SPINLOCK(watchdog_lock);
> > >> static int watchdog_running;
> > >> +static unsigned long watchdog_start_time;
> > >> static atomic_t watchdog_reset_pending;
> > >>
> > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > >> int next_cpu, reset_pending;
> > >> int64_t wd_nsec, cs_nsec;
> > >> struct clocksource *cs;
> > >> + unsigned long max_jiffies;
> > >> u32 md;
> > >>
> > >> spin_lock(&watchdog_lock);
> > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > >> if (atomic_read(&watchdog_reset_pending))
> > >> continue;
> > >>
> > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > >> + continue;
> > >> +
> > >
> > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > updated by counting the number of tick intervals on the current
> > > clocksource.
> > >
> > > This seems like circular logic, where we're trying to judge the
> > > current clocksource by using something we derived from the current
> > > clocksource.
> > > That's why the watchdog clocksource is important, as it's supposed to
> > > be a separate counter that is more reliable (but likely slower) then
> > > the preferred clocksource.
> > >
> > > So I'm not really sure how this helps.
> > >
> > > The earlier patch by yanghui at least used the watchdog interval to
> > > decide if the watchdog timer had expired late. Which seemed
> > > reasonable, but I thought it might be helpful to add some sort of a
> > > counter so if the case is happening repeatedly (timers constantly
> > > being delayed) we have a better signal that the watchdog and current
> > > clocksource are out of sync. Because again, timers are fired based on
> >
> > I think only have a signal ls not enough. we need to prevent
> > clocksource from being incorrectly switched.
>
> Right, but we also have to ensure that we also properly disqualify
> clocksources that are misbehaving.
>
> In the case that the current clocksource is running very slow (imagine
> old TSCs that lowered freq with cpufreq), then system time slows down,
> so timers fire late.
> So it would constantly seem like the irqs are being delayed, so with
> your logic we would not disqualify a clearly malfunctioning
> clocksource..
>
> > The Timer callback function clocksource_watchdog() is executed in the
> > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > long time(One situation is long time softlockup), clocksource_watchdog()
> > will be delay executed.
>
> Yes. The reality is that timers are often spuriously delayed. We don't
> want a short burst of timer misbehavior to disqualify a good
> clocksource.
>
> But the problem is that this situation and the one above (with the
> freq changing TSC), will look exactly the same.
>
> So having a situation where if the watchdog clocksource thinks too
> much time has passed between watchdog timers, we can skip judgement,
> assuming its a spurious delay. But I think we need to keep a counter
> so that if this happens 3-5 times in a row, we stop ignoring the
> misbehavior and judge the current clocksource, as it may be running
> slowly.
>
> > >
> > I think it will be better to add this to my patch:
> > /*
> > * Interval: 0.5sec.
> > - * MaxInterval: 1s.
> > + * MaxInterval: 20s.
> > */
> > #define WATCHDOG_INTERVAL (HZ >> 1)
> > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> >
>
> Some watchdog counters wrap within 20 seconds, so I don't think this
> is a good idea.
>
> The other proposal to calculate the error rate, rather than a fixed
> error boundary might be useful too, as if the current clocksource and
> watchdog are close, a long timer delay won't disqualify them if we
> scale the error bounds to be within an given error rate.

In most of tsc unstable trouble shooting on modern servers we experienced,
it usually ends up in a false alarm triggered by the clock source
watchdog for tsc.

I think Paul has a proposal to make a clock source watchdog to be more
intelligent.
Its job is to find a real problem instead of causing a problem.

so disabling it for known good-tsc might be a reasonable good idea
that can save manpower for other
more valuable problems to solve, or at least make it statistically a
problem less chance to happen.
>
> thanks
> -john

2021-10-20 17:52:00

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> >
> > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > >> John Stultz wrote on 2021/10/12 13:29:
> > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > >>>> verification? Do you think this idea is okay?
> > > >>>
> > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > >>>
> > > >>
> > > >> Sorry, it looks almost as follows:
> > > >>
> > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > >> index b8a14d2..87f3b67 100644
> > > >> --- a/kernel/time/clocksource.c
> > > >> +++ b/kernel/time/clocksource.c
> > > >> @@ -119,6 +119,7 @@
> > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > >> static int watchdog_running;
> > > >> +static unsigned long watchdog_start_time;
> > > >> static atomic_t watchdog_reset_pending;
> > > >>
> > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > >> int next_cpu, reset_pending;
> > > >> int64_t wd_nsec, cs_nsec;
> > > >> struct clocksource *cs;
> > > >> + unsigned long max_jiffies;
> > > >> u32 md;
> > > >>
> > > >> spin_lock(&watchdog_lock);
> > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > >> if (atomic_read(&watchdog_reset_pending))
> > > >> continue;
> > > >>
> > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > >> + continue;
> > > >> +
> > > >
> > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > updated by counting the number of tick intervals on the current
> > > > clocksource.
> > > >
> > > > This seems like circular logic, where we're trying to judge the
> > > > current clocksource by using something we derived from the current
> > > > clocksource.
> > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > be a separate counter that is more reliable (but likely slower) then
> > > > the preferred clocksource.
> > > >
> > > > So I'm not really sure how this helps.
> > > >
> > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > decide if the watchdog timer had expired late. Which seemed
> > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > counter so if the case is happening repeatedly (timers constantly
> > > > being delayed) we have a better signal that the watchdog and current
> > > > clocksource are out of sync. Because again, timers are fired based on
> > >
> > > I think only have a signal ls not enough. we need to prevent
> > > clocksource from being incorrectly switched.
> >
> > Right, but we also have to ensure that we also properly disqualify
> > clocksources that are misbehaving.
> >
> > In the case that the current clocksource is running very slow (imagine
> > old TSCs that lowered freq with cpufreq), then system time slows down,
> > so timers fire late.
> > So it would constantly seem like the irqs are being delayed, so with
> > your logic we would not disqualify a clearly malfunctioning
> > clocksource..
> >
> > > The Timer callback function clocksource_watchdog() is executed in the
> > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > will be delay executed.
> >
> > Yes. The reality is that timers are often spuriously delayed. We don't
> > want a short burst of timer misbehavior to disqualify a good
> > clocksource.
> >
> > But the problem is that this situation and the one above (with the
> > freq changing TSC), will look exactly the same.
> >
> > So having a situation where if the watchdog clocksource thinks too
> > much time has passed between watchdog timers, we can skip judgement,
> > assuming its a spurious delay. But I think we need to keep a counter
> > so that if this happens 3-5 times in a row, we stop ignoring the
> > misbehavior and judge the current clocksource, as it may be running
> > slowly.
> >
> > > >
> > > I think it will be better to add this to my patch:
> > > /*
> > > * Interval: 0.5sec.
> > > - * MaxInterval: 1s.
> > > + * MaxInterval: 20s.
> > > */
> > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > >
> >
> > Some watchdog counters wrap within 20 seconds, so I don't think this
> > is a good idea.
> >
> > The other proposal to calculate the error rate, rather than a fixed
> > error boundary might be useful too, as if the current clocksource and
> > watchdog are close, a long timer delay won't disqualify them if we
> > scale the error bounds to be within an given error rate.
>
> In most of tsc unstable trouble shooting on modern servers we experienced,
> it usually ends up in a false alarm triggered by the clock source
> watchdog for tsc.
>
> I think Paul has a proposal to make a clock source watchdog to be more
> intelligent.
> Its job is to find a real problem instead of causing a problem.

And that proposal is now in mainline:

22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
2e27e793e280 clocksource: Reduce clocksource-skew threshold
fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
db3a34e17433 clocksource: Retry clock read if long delays detected

The strategy is to disqualify a clock comparison if the reads took too
long, and to retry the comparison. If four consecutive comparison take
too long, clock skew is reported. The number of consecutive comparisons
may be adjusted by the usual kernel boot parameter.

> so disabling it for known good-tsc might be a reasonable good idea
> that can save manpower for other
> more valuable problems to solve, or at least make it statistically a
> problem less chance to happen.

One additional piece that is still in prototype state in -rcu is to give
clocksources some opportunity to resynchronize if there are too many
slow comparisons. This is intended to handle cases where clocks often
take hundreds of microseconds to read out due to cache-buster workloads
interfering with all and sundry. Testing indicates that even in the
midst of such cache-busting, there will almost certainly be at least one
fast comparison within a five-second period. So the current thought is
to give a clocksource 100 seconds in which to get a fast comparison.

Those who have only one clock always know what time it is. Those with
more than one can never be certain. Except that the universe is
well-supplied with a great many clocks outside of the computer system
in question. ;-)

Thanx, Paul

2021-10-21 09:38:41

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
>
> On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > >
> > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > >>>> verification? Do you think this idea is okay?
> > > > >>>
> > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > >>>
> > > > >>
> > > > >> Sorry, it looks almost as follows:
> > > > >>
> > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > >> index b8a14d2..87f3b67 100644
> > > > >> --- a/kernel/time/clocksource.c
> > > > >> +++ b/kernel/time/clocksource.c
> > > > >> @@ -119,6 +119,7 @@
> > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > >> static int watchdog_running;
> > > > >> +static unsigned long watchdog_start_time;
> > > > >> static atomic_t watchdog_reset_pending;
> > > > >>
> > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > >> int next_cpu, reset_pending;
> > > > >> int64_t wd_nsec, cs_nsec;
> > > > >> struct clocksource *cs;
> > > > >> + unsigned long max_jiffies;
> > > > >> u32 md;
> > > > >>
> > > > >> spin_lock(&watchdog_lock);
> > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > >> continue;
> > > > >>
> > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > >> + continue;
> > > > >> +
> > > > >
> > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > updated by counting the number of tick intervals on the current
> > > > > clocksource.
> > > > >
> > > > > This seems like circular logic, where we're trying to judge the
> > > > > current clocksource by using something we derived from the current
> > > > > clocksource.
> > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > the preferred clocksource.
> > > > >
> > > > > So I'm not really sure how this helps.
> > > > >
> > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > being delayed) we have a better signal that the watchdog and current
> > > > > clocksource are out of sync. Because again, timers are fired based on
> > > >
> > > > I think only have a signal ls not enough. we need to prevent
> > > > clocksource from being incorrectly switched.
> > >
> > > Right, but we also have to ensure that we also properly disqualify
> > > clocksources that are misbehaving.
> > >
> > > In the case that the current clocksource is running very slow (imagine
> > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > so timers fire late.
> > > So it would constantly seem like the irqs are being delayed, so with
> > > your logic we would not disqualify a clearly malfunctioning
> > > clocksource..
> > >
> > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > will be delay executed.
> > >
> > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > want a short burst of timer misbehavior to disqualify a good
> > > clocksource.
> > >
> > > But the problem is that this situation and the one above (with the
> > > freq changing TSC), will look exactly the same.
> > >
> > > So having a situation where if the watchdog clocksource thinks too
> > > much time has passed between watchdog timers, we can skip judgement,
> > > assuming its a spurious delay. But I think we need to keep a counter
> > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > misbehavior and judge the current clocksource, as it may be running
> > > slowly.
> > >
> > > > >
> > > > I think it will be better to add this to my patch:
> > > > /*
> > > > * Interval: 0.5sec.
> > > > - * MaxInterval: 1s.
> > > > + * MaxInterval: 20s.
> > > > */
> > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > >
> > >
> > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > is a good idea.
> > >
> > > The other proposal to calculate the error rate, rather than a fixed
> > > error boundary might be useful too, as if the current clocksource and
> > > watchdog are close, a long timer delay won't disqualify them if we
> > > scale the error bounds to be within an given error rate.
> >
> > In most of tsc unstable trouble shooting on modern servers we experienced,
> > it usually ends up in a false alarm triggered by the clock source
> > watchdog for tsc.
> >
> > I think Paul has a proposal to make a clock source watchdog to be more
> > intelligent.
> > Its job is to find a real problem instead of causing a problem.
>
> And that proposal is now in mainline:

Great! : -)
>
> 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> db3a34e17433 clocksource: Retry clock read if long delays detected
>
> The strategy is to disqualify a clock comparison if the reads took too
> long, and to retry the comparison. If four consecutive comparison take
> too long, clock skew is reported. The number of consecutive comparisons
> may be adjusted by the usual kernel boot parameter.
>
> > so disabling it for known good-tsc might be a reasonable good idea
> > that can save manpower for other
> > more valuable problems to solve, or at least make it statistically a
> > problem less chance to happen.
>
> One additional piece that is still in prototype state in -rcu is to give
> clocksources some opportunity to resynchronize if there are too many
> slow comparisons. This is intended to handle cases where clocks often

if there is such tsc-sync algorithm existing in software, it really
can help system software engineers
to solve some rare power good signals synchronization problem caused
by bios that caused
boot time tsc sync check failure that usually would consume huge
debugging engine for bringing up qualified linux system.

Less depending on platform quirks should be good thing to linux for
tsc && rcu support.

> take hundreds of microseconds to read out due to cache-buster workloads
> interfering with all and sundry. Testing indicates that even in the
> midst of such cache-busting, there will almost certainly be at least one
> fast comparison within a five-second period. So the current thought is
> to give a clocksource 100 seconds in which to get a fast comparison.
>
> Those who have only one clock always know what time it is. Those with
> more than one can never be certain. Except that the universe is
> well-supplied with a great many clocks outside of the computer system
> in question. ;-)
>
> Thanx, Paul

2021-10-22 23:39:03

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Thu, Oct 21, 2021 at 05:37:24AM -0400, Luming Yu wrote:
> On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
> >
> > On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > > >
> > > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > > >>>> verification? Do you think this idea is okay?
> > > > > >>>
> > > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > > >>>
> > > > > >>
> > > > > >> Sorry, it looks almost as follows:
> > > > > >>
> > > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > >> index b8a14d2..87f3b67 100644
> > > > > >> --- a/kernel/time/clocksource.c
> > > > > >> +++ b/kernel/time/clocksource.c
> > > > > >> @@ -119,6 +119,7 @@
> > > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > > >> static int watchdog_running;
> > > > > >> +static unsigned long watchdog_start_time;
> > > > > >> static atomic_t watchdog_reset_pending;
> > > > > >>
> > > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > >> int next_cpu, reset_pending;
> > > > > >> int64_t wd_nsec, cs_nsec;
> > > > > >> struct clocksource *cs;
> > > > > >> + unsigned long max_jiffies;
> > > > > >> u32 md;
> > > > > >>
> > > > > >> spin_lock(&watchdog_lock);
> > > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > > >> continue;
> > > > > >>
> > > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > > >> + continue;
> > > > > >> +
> > > > > >
> > > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > > updated by counting the number of tick intervals on the current
> > > > > > clocksource.
> > > > > >
> > > > > > This seems like circular logic, where we're trying to judge the
> > > > > > current clocksource by using something we derived from the current
> > > > > > clocksource.
> > > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > > the preferred clocksource.
> > > > > >
> > > > > > So I'm not really sure how this helps.
> > > > > >
> > > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > > being delayed) we have a better signal that the watchdog and current
> > > > > > clocksource are out of sync. Because again, timers are fired based on
> > > > >
> > > > > I think only have a signal ls not enough. we need to prevent
> > > > > clocksource from being incorrectly switched.
> > > >
> > > > Right, but we also have to ensure that we also properly disqualify
> > > > clocksources that are misbehaving.
> > > >
> > > > In the case that the current clocksource is running very slow (imagine
> > > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > > so timers fire late.
> > > > So it would constantly seem like the irqs are being delayed, so with
> > > > your logic we would not disqualify a clearly malfunctioning
> > > > clocksource..
> > > >
> > > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > > will be delay executed.
> > > >
> > > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > > want a short burst of timer misbehavior to disqualify a good
> > > > clocksource.
> > > >
> > > > But the problem is that this situation and the one above (with the
> > > > freq changing TSC), will look exactly the same.
> > > >
> > > > So having a situation where if the watchdog clocksource thinks too
> > > > much time has passed between watchdog timers, we can skip judgement,
> > > > assuming its a spurious delay. But I think we need to keep a counter
> > > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > > misbehavior and judge the current clocksource, as it may be running
> > > > slowly.
> > > >
> > > > > >
> > > > > I think it will be better to add this to my patch:
> > > > > /*
> > > > > * Interval: 0.5sec.
> > > > > - * MaxInterval: 1s.
> > > > > + * MaxInterval: 20s.
> > > > > */
> > > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > > >
> > > >
> > > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > > is a good idea.
> > > >
> > > > The other proposal to calculate the error rate, rather than a fixed
> > > > error boundary might be useful too, as if the current clocksource and
> > > > watchdog are close, a long timer delay won't disqualify them if we
> > > > scale the error bounds to be within an given error rate.
> > >
> > > In most of tsc unstable trouble shooting on modern servers we experienced,
> > > it usually ends up in a false alarm triggered by the clock source
> > > watchdog for tsc.
> > >
> > > I think Paul has a proposal to make a clock source watchdog to be more
> > > intelligent.
> > > Its job is to find a real problem instead of causing a problem.
> >
> > And that proposal is now in mainline:
>
> Great! : -)
> >
> > 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> > 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> > 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> > fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> > 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> > db3a34e17433 clocksource: Retry clock read if long delays detected
> >
> > The strategy is to disqualify a clock comparison if the reads took too
> > long, and to retry the comparison. If four consecutive comparison take
> > too long, clock skew is reported. The number of consecutive comparisons
> > may be adjusted by the usual kernel boot parameter.
> >
> > > so disabling it for known good-tsc might be a reasonable good idea
> > > that can save manpower for other
> > > more valuable problems to solve, or at least make it statistically a
> > > problem less chance to happen.
> >
> > One additional piece that is still in prototype state in -rcu is to give
> > clocksources some opportunity to resynchronize if there are too many
> > slow comparisons. This is intended to handle cases where clocks often
>
> if there is such tsc-sync algorithm existing in software, it really
> can help system software engineers
> to solve some rare power good signals synchronization problem caused
> by bios that caused
> boot time tsc sync check failure that usually would consume huge
> debugging engine for bringing up qualified linux system.
>
> Less depending on platform quirks should be good thing to linux for
> tsc && rcu support.

Good point, I have procrastinated long enough.

How about like this?

Thanx, Paul

------------------------------------------------------------------------

commit 9ec2a03bbf4bee3d9fbc02a402dee36efafc5a2d
Author: Paul E. McKenney <[email protected]>
Date: Thu May 27 11:03:28 2021 -0700

clocksource: Forgive repeated long-latency watchdog clocksource reads

Currently, the clocksource watchdog reacts to repeated long-latency
clocksource reads by marking that clocksource unstable on the theory that
these long-latency reads are a sign of a serious problem. And this theory
does in fact have real-world support in the form of firmware issues [1].

However, it is also possible to trigger this using stress-ng on what
the stress-ng man page terms "poorly designed hardware" [2]. And it
is not necessarily a bad thing for the kernel to diagnose cases where
heavy memory-contention workloads are being run on hardware that is not
designed for this sort of use.

Nevertheless, it is quite possible that real-world use will result in
some situation requiring that high-stress workloads run on hardware
not designed to accommodate them, and also requiring that the kernel
refrain from marking clocksources unstable.

Therefore, react to persistent long-latency reads by leaving the
clocksource alone, but using the old 62.5-millisecond skew-detection
threshold. In addition, the offending clocksource is marked for
re-initialization, which both restarts that clocksource with a clean bill
of health and avoids false-positive skew reports on later watchdog checks.
Once marked for re-initialization, the clocksource is not subjected to
further watchdog checking until a subsequent successful read from that
clocksource that is free of excessive delays.

However, if clocksource.max_cswd_coarse_reads consecutive clocksource read
attempts result in long latencies, a warning (splat) will be emitted.
This kernel boot parameter defaults to 100, and this warning can be
disabled by setting it to zero or to a negative value.

[ paulmck: Apply feedback from Chao Gao ]

Link: https://lore.kernel.org/lkml/20210513155515.GB23902@xsang-OptiPlex-9020/ # [1]
Link: https://lore.kernel.org/lkml/20210521083322.GG25531@xsang-OptiPlex-9020/ # [2]
Link: https://lore.kernel.org/lkml/20210521084405.GH25531@xsang-OptiPlex-9020/
Link: https://lore.kernel.org/lkml/20210511233403.GA2896757@paulmck-ThinkPad-P17-Gen-1/
Tested-by: Chao Gao <[email protected]>
Signed-off-by: Paul E. McKenney <[email protected]>

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 316027c3aadc..61d2436ae9df 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -600,6 +600,14 @@
loops can be debugged more effectively on production
systems.

+ clocksource.max_cswd_coarse_reads= [KNL]
+ Number of consecutive clocksource_watchdog()
+ coarse reads (that is, clocksource reads that
+ were unduly delayed) that are permitted before
+ the kernel complains (gently). Set to a value
+ less than or equal to zero to suppress these
+ complaints.
+
clocksource.max_cswd_read_retries= [KNL]
Number of clocksource_watchdog() retries due to
external delays before the clock will be marked
diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
index 1d42d4b17327..3e925d9ffc31 100644
--- a/include/linux/clocksource.h
+++ b/include/linux/clocksource.h
@@ -110,6 +110,7 @@ struct clocksource {
int rating;
enum clocksource_ids id;
enum vdso_clock_mode vdso_clock_mode;
+ unsigned int n_coarse_reads;
unsigned long flags;

int (*enable)(struct clocksource *cs);
@@ -291,6 +292,7 @@ static inline void timer_probe(void) {}
#define TIMER_ACPI_DECLARE(name, table_id, fn) \
ACPI_DECLARE_PROBE_ENTRY(timer, name, table_id, 0, NULL, 0, fn)

+extern int max_cswd_coarse_reads;
extern ulong max_cswd_read_retries;
void clocksource_verify_percpu(struct clocksource *cs);

diff --git a/kernel/time/clocksource-wdtest.c b/kernel/time/clocksource-wdtest.c
index df922f49d171..7e82500c400b 100644
--- a/kernel/time/clocksource-wdtest.c
+++ b/kernel/time/clocksource-wdtest.c
@@ -145,13 +145,12 @@ static int wdtest_func(void *arg)
else if (i <= max_cswd_read_retries)
s = ", expect message";
else
- s = ", expect clock skew";
+ s = ", expect coarse-grained clock skew check and re-initialization";
pr_info("--- Watchdog with %dx error injection, %lu retries%s.\n", i, max_cswd_read_retries, s);
WRITE_ONCE(wdtest_ktime_read_ndelays, i);
schedule_timeout_uninterruptible(2 * HZ);
WARN_ON_ONCE(READ_ONCE(wdtest_ktime_read_ndelays));
- WARN_ON_ONCE((i <= max_cswd_read_retries) !=
- !(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE));
+ WARN_ON_ONCE(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE);
wdtest_ktime_clocksource_reset();
}

diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
index b8a14d2fb5ba..796a127aabb9 100644
--- a/kernel/time/clocksource.c
+++ b/kernel/time/clocksource.c
@@ -199,6 +199,9 @@ void clocksource_mark_unstable(struct clocksource *cs)
spin_unlock_irqrestore(&watchdog_lock, flags);
}

+int max_cswd_coarse_reads = 100;
+module_param(max_cswd_coarse_reads, int, 0644);
+EXPORT_SYMBOL_GPL(max_cswd_coarse_reads);
ulong max_cswd_read_retries = 3;
module_param(max_cswd_read_retries, ulong, 0644);
EXPORT_SYMBOL_GPL(max_cswd_read_retries);
@@ -226,13 +229,22 @@ static bool cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
smp_processor_id(), watchdog->name, nretries);
}
- return true;
+ cs->n_coarse_reads = 0;
+ return false;
}
+ WARN_ONCE(max_cswd_coarse_reads > 0 &&
+ !(++cs->n_coarse_reads % max_cswd_coarse_reads),
+ "timekeeping watchdog on CPU%d: %s %u consecutive coarse-grained reads\n", smp_processor_id(), watchdog->name, cs->n_coarse_reads);
}

- pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, marking unstable\n",
- smp_processor_id(), watchdog->name, wd_delay, nretries);
- return false;
+ if ((cs->flags & CLOCK_SOURCE_WATCHDOG) && !atomic_read(&watchdog_reset_pending)) {
+ pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, coarse-grained skew check followed by re-initialization\n",
+ smp_processor_id(), watchdog->name, wd_delay, nretries);
+ } else {
+ pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, awaiting re-initialization\n",
+ smp_processor_id(), watchdog->name, wd_delay, nretries);
+ }
+ return true;
}

static u64 csnow_mid;
@@ -356,6 +368,7 @@ static void clocksource_watchdog(struct timer_list *unused)
int next_cpu, reset_pending;
int64_t wd_nsec, cs_nsec;
struct clocksource *cs;
+ bool coarse;
u32 md;

spin_lock(&watchdog_lock);
@@ -373,16 +386,13 @@ static void clocksource_watchdog(struct timer_list *unused)
continue;
}

- if (!cs_watchdog_read(cs, &csnow, &wdnow)) {
- /* Clock readout unreliable, so give it up. */
- __clocksource_unstable(cs);
- continue;
- }
+ coarse = cs_watchdog_read(cs, &csnow, &wdnow);

/* Clocksource initialized ? */
if (!(cs->flags & CLOCK_SOURCE_WATCHDOG) ||
atomic_read(&watchdog_reset_pending)) {
- cs->flags |= CLOCK_SOURCE_WATCHDOG;
+ if (!coarse)
+ cs->flags |= CLOCK_SOURCE_WATCHDOG;
cs->wd_last = wdnow;
cs->cs_last = csnow;
continue;
@@ -403,7 +413,13 @@ static void clocksource_watchdog(struct timer_list *unused)
continue;

/* Check the deviation from the watchdog clocksource. */
- md = cs->uncertainty_margin + watchdog->uncertainty_margin;
+ if (coarse) {
+ md = 62500 * NSEC_PER_USEC;
+ cs->flags &= ~CLOCK_SOURCE_WATCHDOG;
+ pr_warn("timekeeping watchdog on CPU%d: %s coarse-grained %lu.%03lu ms clock-skew check followed by re-initialization\n", smp_processor_id(), watchdog->name, md / NSEC_PER_MSEC, md % NSEC_PER_MSEC / NSEC_PER_USEC);
+ } else {
+ md = cs->uncertainty_margin + watchdog->uncertainty_margin;
+ }
if (abs(cs_nsec - wd_nsec) > md) {
pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as unstable because the skew is too large:\n",
smp_processor_id(), cs->name);

2021-11-01 10:12:10

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Fri, Oct 22, 2021 at 7:36 PM Paul E. McKenney <[email protected]> wrote:
>
> On Thu, Oct 21, 2021 at 05:37:24AM -0400, Luming Yu wrote:
> > On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
> > >
> > > On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > > > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > > > >
> > > > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > > > >>>> verification? Do you think this idea is okay?
> > > > > > >>>
> > > > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > > > >>>
> > > > > > >>
> > > > > > >> Sorry, it looks almost as follows:
> > > > > > >>
> > > > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > > >> index b8a14d2..87f3b67 100644
> > > > > > >> --- a/kernel/time/clocksource.c
> > > > > > >> +++ b/kernel/time/clocksource.c
> > > > > > >> @@ -119,6 +119,7 @@
> > > > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > > > >> static int watchdog_running;
> > > > > > >> +static unsigned long watchdog_start_time;
> > > > > > >> static atomic_t watchdog_reset_pending;
> > > > > > >>
> > > > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > >> int next_cpu, reset_pending;
> > > > > > >> int64_t wd_nsec, cs_nsec;
> > > > > > >> struct clocksource *cs;
> > > > > > >> + unsigned long max_jiffies;
> > > > > > >> u32 md;
> > > > > > >>
> > > > > > >> spin_lock(&watchdog_lock);
> > > > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > > > >> continue;
> > > > > > >>
> > > > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > > > >> + continue;
> > > > > > >> +
> > > > > > >
> > > > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > > > updated by counting the number of tick intervals on the current
> > > > > > > clocksource.
> > > > > > >
> > > > > > > This seems like circular logic, where we're trying to judge the
> > > > > > > current clocksource by using something we derived from the current
> > > > > > > clocksource.
> > > > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > > > the preferred clocksource.
> > > > > > >
> > > > > > > So I'm not really sure how this helps.
> > > > > > >
> > > > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > > > being delayed) we have a better signal that the watchdog and current
> > > > > > > clocksource are out of sync. Because again, timers are fired based on
> > > > > >
> > > > > > I think only have a signal ls not enough. we need to prevent
> > > > > > clocksource from being incorrectly switched.
> > > > >
> > > > > Right, but we also have to ensure that we also properly disqualify
> > > > > clocksources that are misbehaving.
> > > > >
> > > > > In the case that the current clocksource is running very slow (imagine
> > > > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > > > so timers fire late.
> > > > > So it would constantly seem like the irqs are being delayed, so with
> > > > > your logic we would not disqualify a clearly malfunctioning
> > > > > clocksource..
> > > > >
> > > > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > > > will be delay executed.
> > > > >
> > > > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > > > want a short burst of timer misbehavior to disqualify a good
> > > > > clocksource.
> > > > >
> > > > > But the problem is that this situation and the one above (with the
> > > > > freq changing TSC), will look exactly the same.
> > > > >
> > > > > So having a situation where if the watchdog clocksource thinks too
> > > > > much time has passed between watchdog timers, we can skip judgement,
> > > > > assuming its a spurious delay. But I think we need to keep a counter
> > > > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > > > misbehavior and judge the current clocksource, as it may be running
> > > > > slowly.
> > > > >
> > > > > > >
> > > > > > I think it will be better to add this to my patch:
> > > > > > /*
> > > > > > * Interval: 0.5sec.
> > > > > > - * MaxInterval: 1s.
> > > > > > + * MaxInterval: 20s.
> > > > > > */
> > > > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > > > >
> > > > >
> > > > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > > > is a good idea.
> > > > >
> > > > > The other proposal to calculate the error rate, rather than a fixed
> > > > > error boundary might be useful too, as if the current clocksource and
> > > > > watchdog are close, a long timer delay won't disqualify them if we
> > > > > scale the error bounds to be within an given error rate.
> > > >
> > > > In most of tsc unstable trouble shooting on modern servers we experienced,
> > > > it usually ends up in a false alarm triggered by the clock source
> > > > watchdog for tsc.
> > > >
> > > > I think Paul has a proposal to make a clock source watchdog to be more
> > > > intelligent.
> > > > Its job is to find a real problem instead of causing a problem.
> > >
> > > And that proposal is now in mainline:
> >
> > Great! : -)
> > >
> > > 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> > > 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> > > 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> > > fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> > > 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> > > db3a34e17433 clocksource: Retry clock read if long delays detected
> > >
> > > The strategy is to disqualify a clock comparison if the reads took too
> > > long, and to retry the comparison. If four consecutive comparison take
> > > too long, clock skew is reported. The number of consecutive comparisons
> > > may be adjusted by the usual kernel boot parameter.
> > >
> > > > so disabling it for known good-tsc might be a reasonable good idea
> > > > that can save manpower for other
> > > > more valuable problems to solve, or at least make it statistically a
> > > > problem less chance to happen.
> > >
> > > One additional piece that is still in prototype state in -rcu is to give
> > > clocksources some opportunity to resynchronize if there are too many
> > > slow comparisons. This is intended to handle cases where clocks often
> >
> > if there is such tsc-sync algorithm existing in software, it really
> > can help system software engineers
> > to solve some rare power good signals synchronization problem caused
> > by bios that caused
> > boot time tsc sync check failure that usually would consume huge
> > debugging engine for bringing up qualified linux system.
> >
> > Less depending on platform quirks should be good thing to linux for
> > tsc && rcu support.
>
> Good point, I have procrastinated long enough.
>
> How about like this?

sorry, I meant a better algorithm to use tsc adjust register
like the tried one in arch/x86/kernel/tsc_sync.c

>
> Thanx, Paul
>
> ------------------------------------------------------------------------
>
> commit 9ec2a03bbf4bee3d9fbc02a402dee36efafc5a2d
> Author: Paul E. McKenney <[email protected]>
> Date: Thu May 27 11:03:28 2021 -0700
>
> clocksource: Forgive repeated long-latency watchdog clocksource reads
>
> Currently, the clocksource watchdog reacts to repeated long-latency
> clocksource reads by marking that clocksource unstable on the theory that
> these long-latency reads are a sign of a serious problem. And this theory

Maybe we need to use other core's tsc as a reference clock instead of
using HPET, which , to my knowledge , is the place where the problem happens.

Ruling out HPET and other slow clock devices as the obvious wrong choice
of a reference clock for tsc, I guess there will be less chance we
(in kernel code)
will get bothered by other latency problems perceived in the clock
source watchdog.

> does in fact have real-world support in the form of firmware issues [1].
>
> However, it is also possible to trigger this using stress-ng on what
> the stress-ng man page terms "poorly designed hardware" [2]. And it
> is not necessarily a bad thing for the kernel to diagnose cases where
> heavy memory-contention workloads are being run on hardware that is not
> designed for this sort of use.
>
> Nevertheless, it is quite possible that real-world use will result in
> some situation requiring that high-stress workloads run on hardware
> not designed to accommodate them, and also requiring that the kernel
> refrain from marking clocksources unstable.
>
> Therefore, react to persistent long-latency reads by leaving the
> clocksource alone, but using the old 62.5-millisecond skew-detection
> threshold. In addition, the offending clocksource is marked for
> re-initialization, which both restarts that clocksource with a clean bill
> of health and avoids false-positive skew reports on later watchdog checks.
> Once marked for re-initialization, the clocksource is not subjected to
> further watchdog checking until a subsequent successful read from that
> clocksource that is free of excessive delays.
>
> However, if clocksource.max_cswd_coarse_reads consecutive clocksource read
> attempts result in long latencies, a warning (splat) will be emitted.
> This kernel boot parameter defaults to 100, and this warning can be
> disabled by setting it to zero or to a negative value.
>
> [ paulmck: Apply feedback from Chao Gao ]
>
> Link: https://lore.kernel.org/lkml/20210513155515.GB23902@xsang-OptiPlex-9020/ # [1]
> Link: https://lore.kernel.org/lkml/20210521083322.GG25531@xsang-OptiPlex-9020/ # [2]
> Link: https://lore.kernel.org/lkml/20210521084405.GH25531@xsang-OptiPlex-9020/
> Link: https://lore.kernel.org/lkml/20210511233403.GA2896757@paulmck-ThinkPad-P17-Gen-1/
> Tested-by: Chao Gao <[email protected]>
> Signed-off-by: Paul E. McKenney <[email protected]>
>
> diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> index 316027c3aadc..61d2436ae9df 100644
> --- a/Documentation/admin-guide/kernel-parameters.txt
> +++ b/Documentation/admin-guide/kernel-parameters.txt
> @@ -600,6 +600,14 @@
> loops can be debugged more effectively on production
> systems.
>
> + clocksource.max_cswd_coarse_reads= [KNL]
> + Number of consecutive clocksource_watchdog()
> + coarse reads (that is, clocksource reads that
> + were unduly delayed) that are permitted before
> + the kernel complains (gently). Set to a value
> + less than or equal to zero to suppress these
> + complaints.
> +
> clocksource.max_cswd_read_retries= [KNL]
> Number of clocksource_watchdog() retries due to
> external delays before the clock will be marked
> diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
> index 1d42d4b17327..3e925d9ffc31 100644
> --- a/include/linux/clocksource.h
> +++ b/include/linux/clocksource.h
> @@ -110,6 +110,7 @@ struct clocksource {
> int rating;
> enum clocksource_ids id;
> enum vdso_clock_mode vdso_clock_mode;
> + unsigned int n_coarse_reads;
> unsigned long flags;
>
> int (*enable)(struct clocksource *cs);
> @@ -291,6 +292,7 @@ static inline void timer_probe(void) {}
> #define TIMER_ACPI_DECLARE(name, table_id, fn) \
> ACPI_DECLARE_PROBE_ENTRY(timer, name, table_id, 0, NULL, 0, fn)
>
> +extern int max_cswd_coarse_reads;
> extern ulong max_cswd_read_retries;
> void clocksource_verify_percpu(struct clocksource *cs);
>
> diff --git a/kernel/time/clocksource-wdtest.c b/kernel/time/clocksource-wdtest.c
> index df922f49d171..7e82500c400b 100644
> --- a/kernel/time/clocksource-wdtest.c
> +++ b/kernel/time/clocksource-wdtest.c
> @@ -145,13 +145,12 @@ static int wdtest_func(void *arg)
> else if (i <= max_cswd_read_retries)
> s = ", expect message";
> else
> - s = ", expect clock skew";
> + s = ", expect coarse-grained clock skew check and re-initialization";
> pr_info("--- Watchdog with %dx error injection, %lu retries%s.\n", i, max_cswd_read_retries, s);
> WRITE_ONCE(wdtest_ktime_read_ndelays, i);
> schedule_timeout_uninterruptible(2 * HZ);
> WARN_ON_ONCE(READ_ONCE(wdtest_ktime_read_ndelays));
> - WARN_ON_ONCE((i <= max_cswd_read_retries) !=
> - !(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE));
> + WARN_ON_ONCE(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE);
> wdtest_ktime_clocksource_reset();
> }
>
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index b8a14d2fb5ba..796a127aabb9 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -199,6 +199,9 @@ void clocksource_mark_unstable(struct clocksource *cs)
> spin_unlock_irqrestore(&watchdog_lock, flags);
> }
>
> +int max_cswd_coarse_reads = 100;
> +module_param(max_cswd_coarse_reads, int, 0644);
> +EXPORT_SYMBOL_GPL(max_cswd_coarse_reads);
> ulong max_cswd_read_retries = 3;
> module_param(max_cswd_read_retries, ulong, 0644);
> EXPORT_SYMBOL_GPL(max_cswd_read_retries);
> @@ -226,13 +229,22 @@ static bool cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
> pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
> smp_processor_id(), watchdog->name, nretries);
> }
> - return true;
> + cs->n_coarse_reads = 0;
> + return false;
> }
> + WARN_ONCE(max_cswd_coarse_reads > 0 &&
> + !(++cs->n_coarse_reads % max_cswd_coarse_reads),
> + "timekeeping watchdog on CPU%d: %s %u consecutive coarse-grained reads\n", smp_processor_id(), watchdog->name, cs->n_coarse_reads);
> }
>
> - pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, marking unstable\n",
> - smp_processor_id(), watchdog->name, wd_delay, nretries);
> - return false;
> + if ((cs->flags & CLOCK_SOURCE_WATCHDOG) && !atomic_read(&watchdog_reset_pending)) {
> + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, coarse-grained skew check followed by re-initialization\n",
> + smp_processor_id(), watchdog->name, wd_delay, nretries);
> + } else {
> + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, awaiting re-initialization\n",
> + smp_processor_id(), watchdog->name, wd_delay, nretries);
> + }
> + return true;
> }
>
> static u64 csnow_mid;
> @@ -356,6 +368,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> int next_cpu, reset_pending;
> int64_t wd_nsec, cs_nsec;
> struct clocksource *cs;
> + bool coarse;
> u32 md;
>
> spin_lock(&watchdog_lock);
> @@ -373,16 +386,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> continue;
> }
>
> - if (!cs_watchdog_read(cs, &csnow, &wdnow)) {
> - /* Clock readout unreliable, so give it up. */
> - __clocksource_unstable(cs);
> - continue;
> - }
> + coarse = cs_watchdog_read(cs, &csnow, &wdnow);
>
> /* Clocksource initialized ? */
> if (!(cs->flags & CLOCK_SOURCE_WATCHDOG) ||
> atomic_read(&watchdog_reset_pending)) {
> - cs->flags |= CLOCK_SOURCE_WATCHDOG;
> + if (!coarse)
> + cs->flags |= CLOCK_SOURCE_WATCHDOG;
> cs->wd_last = wdnow;
> cs->cs_last = csnow;
> continue;
> @@ -403,7 +413,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> continue;
>
> /* Check the deviation from the watchdog clocksource. */
> - md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> + if (coarse) {
> + md = 62500 * NSEC_PER_USEC;
> + cs->flags &= ~CLOCK_SOURCE_WATCHDOG;
> + pr_warn("timekeeping watchdog on CPU%d: %s coarse-grained %lu.%03lu ms clock-skew check followed by re-initialization\n", smp_processor_id(), watchdog->name, md / NSEC_PER_MSEC, md % NSEC_PER_MSEC / NSEC_PER_USEC);
> + } else {
> + md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> + }
> if (abs(cs_nsec - wd_nsec) > md) {
> pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as unstable because the skew is too large:\n",
> smp_processor_id(), cs->name);

2021-11-01 16:58:14

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Mon, Nov 01, 2021 at 05:59:52AM -0400, Luming Yu wrote:
> On Fri, Oct 22, 2021 at 7:36 PM Paul E. McKenney <[email protected]> wrote:
> >
> > On Thu, Oct 21, 2021 at 05:37:24AM -0400, Luming Yu wrote:
> > > On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
> > > >
> > > > On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > > > > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > > > > >
> > > > > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > > > > >>>> verification? Do you think this idea is okay?
> > > > > > > >>>
> > > > > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > > > > >>>
> > > > > > > >>
> > > > > > > >> Sorry, it looks almost as follows:
> > > > > > > >>
> > > > > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > > > >> index b8a14d2..87f3b67 100644
> > > > > > > >> --- a/kernel/time/clocksource.c
> > > > > > > >> +++ b/kernel/time/clocksource.c
> > > > > > > >> @@ -119,6 +119,7 @@
> > > > > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > > > > >> static int watchdog_running;
> > > > > > > >> +static unsigned long watchdog_start_time;
> > > > > > > >> static atomic_t watchdog_reset_pending;
> > > > > > > >>
> > > > > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > >> int next_cpu, reset_pending;
> > > > > > > >> int64_t wd_nsec, cs_nsec;
> > > > > > > >> struct clocksource *cs;
> > > > > > > >> + unsigned long max_jiffies;
> > > > > > > >> u32 md;
> > > > > > > >>
> > > > > > > >> spin_lock(&watchdog_lock);
> > > > > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > > > > >> continue;
> > > > > > > >>
> > > > > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > > > > >> + continue;
> > > > > > > >> +
> > > > > > > >
> > > > > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > > > > updated by counting the number of tick intervals on the current
> > > > > > > > clocksource.
> > > > > > > >
> > > > > > > > This seems like circular logic, where we're trying to judge the
> > > > > > > > current clocksource by using something we derived from the current
> > > > > > > > clocksource.
> > > > > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > > > > the preferred clocksource.
> > > > > > > >
> > > > > > > > So I'm not really sure how this helps.
> > > > > > > >
> > > > > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > > > > being delayed) we have a better signal that the watchdog and current
> > > > > > > > clocksource are out of sync. Because again, timers are fired based on
> > > > > > >
> > > > > > > I think only have a signal ls not enough. we need to prevent
> > > > > > > clocksource from being incorrectly switched.
> > > > > >
> > > > > > Right, but we also have to ensure that we also properly disqualify
> > > > > > clocksources that are misbehaving.
> > > > > >
> > > > > > In the case that the current clocksource is running very slow (imagine
> > > > > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > > > > so timers fire late.
> > > > > > So it would constantly seem like the irqs are being delayed, so with
> > > > > > your logic we would not disqualify a clearly malfunctioning
> > > > > > clocksource..
> > > > > >
> > > > > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > > > > will be delay executed.
> > > > > >
> > > > > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > > > > want a short burst of timer misbehavior to disqualify a good
> > > > > > clocksource.
> > > > > >
> > > > > > But the problem is that this situation and the one above (with the
> > > > > > freq changing TSC), will look exactly the same.
> > > > > >
> > > > > > So having a situation where if the watchdog clocksource thinks too
> > > > > > much time has passed between watchdog timers, we can skip judgement,
> > > > > > assuming its a spurious delay. But I think we need to keep a counter
> > > > > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > > > > misbehavior and judge the current clocksource, as it may be running
> > > > > > slowly.
> > > > > >
> > > > > > > >
> > > > > > > I think it will be better to add this to my patch:
> > > > > > > /*
> > > > > > > * Interval: 0.5sec.
> > > > > > > - * MaxInterval: 1s.
> > > > > > > + * MaxInterval: 20s.
> > > > > > > */
> > > > > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > > > > >
> > > > > >
> > > > > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > > > > is a good idea.
> > > > > >
> > > > > > The other proposal to calculate the error rate, rather than a fixed
> > > > > > error boundary might be useful too, as if the current clocksource and
> > > > > > watchdog are close, a long timer delay won't disqualify them if we
> > > > > > scale the error bounds to be within an given error rate.
> > > > >
> > > > > In most of tsc unstable trouble shooting on modern servers we experienced,
> > > > > it usually ends up in a false alarm triggered by the clock source
> > > > > watchdog for tsc.
> > > > >
> > > > > I think Paul has a proposal to make a clock source watchdog to be more
> > > > > intelligent.
> > > > > Its job is to find a real problem instead of causing a problem.
> > > >
> > > > And that proposal is now in mainline:
> > >
> > > Great! : -)
> > > >
> > > > 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> > > > 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> > > > 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> > > > fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> > > > 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> > > > db3a34e17433 clocksource: Retry clock read if long delays detected
> > > >
> > > > The strategy is to disqualify a clock comparison if the reads took too
> > > > long, and to retry the comparison. If four consecutive comparison take
> > > > too long, clock skew is reported. The number of consecutive comparisons
> > > > may be adjusted by the usual kernel boot parameter.
> > > >
> > > > > so disabling it for known good-tsc might be a reasonable good idea
> > > > > that can save manpower for other
> > > > > more valuable problems to solve, or at least make it statistically a
> > > > > problem less chance to happen.
> > > >
> > > > One additional piece that is still in prototype state in -rcu is to give
> > > > clocksources some opportunity to resynchronize if there are too many
> > > > slow comparisons. This is intended to handle cases where clocks often
> > >
> > > if there is such tsc-sync algorithm existing in software, it really
> > > can help system software engineers
> > > to solve some rare power good signals synchronization problem caused
> > > by bios that caused
> > > boot time tsc sync check failure that usually would consume huge
> > > debugging engine for bringing up qualified linux system.
> > >
> > > Less depending on platform quirks should be good thing to linux for
> > > tsc && rcu support.
> >
> > Good point, I have procrastinated long enough.
> >
> > How about like this?
>
> sorry, I meant a better algorithm to use tsc adjust register
> like the tried one in arch/x86/kernel/tsc_sync.c

Ah, at this time I must leave that sort of task to others.

Thanx, Paul

> > ------------------------------------------------------------------------
> >
> > commit 9ec2a03bbf4bee3d9fbc02a402dee36efafc5a2d
> > Author: Paul E. McKenney <[email protected]>
> > Date: Thu May 27 11:03:28 2021 -0700
> >
> > clocksource: Forgive repeated long-latency watchdog clocksource reads
> >
> > Currently, the clocksource watchdog reacts to repeated long-latency
> > clocksource reads by marking that clocksource unstable on the theory that
> > these long-latency reads are a sign of a serious problem. And this theory
>
> Maybe we need to use other core's tsc as a reference clock instead of
> using HPET, which , to my knowledge , is the place where the problem happens.
>
> Ruling out HPET and other slow clock devices as the obvious wrong choice
> of a reference clock for tsc, I guess there will be less chance we
> (in kernel code)
> will get bothered by other latency problems perceived in the clock
> source watchdog.

There have been a number of patches that identify systems that tend to
have unreliable HPET implementations. Perhaps more systems are needed
there, or maybe some of those patches need to be backported to the
version of Linux that you are using.

There was also a patch that identified systems that are expected to have
reliable TSCs, and that de-emphasized HPET on such systems.

Thanx, Paul

> > does in fact have real-world support in the form of firmware issues [1].
> >
> > However, it is also possible to trigger this using stress-ng on what
> > the stress-ng man page terms "poorly designed hardware" [2]. And it
> > is not necessarily a bad thing for the kernel to diagnose cases where
> > heavy memory-contention workloads are being run on hardware that is not
> > designed for this sort of use.
> >
> > Nevertheless, it is quite possible that real-world use will result in
> > some situation requiring that high-stress workloads run on hardware
> > not designed to accommodate them, and also requiring that the kernel
> > refrain from marking clocksources unstable.
> >
> > Therefore, react to persistent long-latency reads by leaving the
> > clocksource alone, but using the old 62.5-millisecond skew-detection
> > threshold. In addition, the offending clocksource is marked for
> > re-initialization, which both restarts that clocksource with a clean bill
> > of health and avoids false-positive skew reports on later watchdog checks.
> > Once marked for re-initialization, the clocksource is not subjected to
> > further watchdog checking until a subsequent successful read from that
> > clocksource that is free of excessive delays.
> >
> > However, if clocksource.max_cswd_coarse_reads consecutive clocksource read
> > attempts result in long latencies, a warning (splat) will be emitted.
> > This kernel boot parameter defaults to 100, and this warning can be
> > disabled by setting it to zero or to a negative value.
> >
> > [ paulmck: Apply feedback from Chao Gao ]
> >
> > Link: https://lore.kernel.org/lkml/20210513155515.GB23902@xsang-OptiPlex-9020/ # [1]
> > Link: https://lore.kernel.org/lkml/20210521083322.GG25531@xsang-OptiPlex-9020/ # [2]
> > Link: https://lore.kernel.org/lkml/20210521084405.GH25531@xsang-OptiPlex-9020/
> > Link: https://lore.kernel.org/lkml/20210511233403.GA2896757@paulmck-ThinkPad-P17-Gen-1/
> > Tested-by: Chao Gao <[email protected]>
> > Signed-off-by: Paul E. McKenney <[email protected]>
> >
> > diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> > index 316027c3aadc..61d2436ae9df 100644
> > --- a/Documentation/admin-guide/kernel-parameters.txt
> > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > @@ -600,6 +600,14 @@
> > loops can be debugged more effectively on production
> > systems.
> >
> > + clocksource.max_cswd_coarse_reads= [KNL]
> > + Number of consecutive clocksource_watchdog()
> > + coarse reads (that is, clocksource reads that
> > + were unduly delayed) that are permitted before
> > + the kernel complains (gently). Set to a value
> > + less than or equal to zero to suppress these
> > + complaints.
> > +
> > clocksource.max_cswd_read_retries= [KNL]
> > Number of clocksource_watchdog() retries due to
> > external delays before the clock will be marked
> > diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
> > index 1d42d4b17327..3e925d9ffc31 100644
> > --- a/include/linux/clocksource.h
> > +++ b/include/linux/clocksource.h
> > @@ -110,6 +110,7 @@ struct clocksource {
> > int rating;
> > enum clocksource_ids id;
> > enum vdso_clock_mode vdso_clock_mode;
> > + unsigned int n_coarse_reads;
> > unsigned long flags;
> >
> > int (*enable)(struct clocksource *cs);
> > @@ -291,6 +292,7 @@ static inline void timer_probe(void) {}
> > #define TIMER_ACPI_DECLARE(name, table_id, fn) \
> > ACPI_DECLARE_PROBE_ENTRY(timer, name, table_id, 0, NULL, 0, fn)
> >
> > +extern int max_cswd_coarse_reads;
> > extern ulong max_cswd_read_retries;
> > void clocksource_verify_percpu(struct clocksource *cs);
> >
> > diff --git a/kernel/time/clocksource-wdtest.c b/kernel/time/clocksource-wdtest.c
> > index df922f49d171..7e82500c400b 100644
> > --- a/kernel/time/clocksource-wdtest.c
> > +++ b/kernel/time/clocksource-wdtest.c
> > @@ -145,13 +145,12 @@ static int wdtest_func(void *arg)
> > else if (i <= max_cswd_read_retries)
> > s = ", expect message";
> > else
> > - s = ", expect clock skew";
> > + s = ", expect coarse-grained clock skew check and re-initialization";
> > pr_info("--- Watchdog with %dx error injection, %lu retries%s.\n", i, max_cswd_read_retries, s);
> > WRITE_ONCE(wdtest_ktime_read_ndelays, i);
> > schedule_timeout_uninterruptible(2 * HZ);
> > WARN_ON_ONCE(READ_ONCE(wdtest_ktime_read_ndelays));
> > - WARN_ON_ONCE((i <= max_cswd_read_retries) !=
> > - !(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE));
> > + WARN_ON_ONCE(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE);
> > wdtest_ktime_clocksource_reset();
> > }
> >
> > diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > index b8a14d2fb5ba..796a127aabb9 100644
> > --- a/kernel/time/clocksource.c
> > +++ b/kernel/time/clocksource.c
> > @@ -199,6 +199,9 @@ void clocksource_mark_unstable(struct clocksource *cs)
> > spin_unlock_irqrestore(&watchdog_lock, flags);
> > }
> >
> > +int max_cswd_coarse_reads = 100;
> > +module_param(max_cswd_coarse_reads, int, 0644);
> > +EXPORT_SYMBOL_GPL(max_cswd_coarse_reads);
> > ulong max_cswd_read_retries = 3;
> > module_param(max_cswd_read_retries, ulong, 0644);
> > EXPORT_SYMBOL_GPL(max_cswd_read_retries);
> > @@ -226,13 +229,22 @@ static bool cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
> > pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
> > smp_processor_id(), watchdog->name, nretries);
> > }
> > - return true;
> > + cs->n_coarse_reads = 0;
> > + return false;
> > }
> > + WARN_ONCE(max_cswd_coarse_reads > 0 &&
> > + !(++cs->n_coarse_reads % max_cswd_coarse_reads),
> > + "timekeeping watchdog on CPU%d: %s %u consecutive coarse-grained reads\n", smp_processor_id(), watchdog->name, cs->n_coarse_reads);
> > }
> >
> > - pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, marking unstable\n",
> > - smp_processor_id(), watchdog->name, wd_delay, nretries);
> > - return false;
> > + if ((cs->flags & CLOCK_SOURCE_WATCHDOG) && !atomic_read(&watchdog_reset_pending)) {
> > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, coarse-grained skew check followed by re-initialization\n",
> > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > + } else {
> > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, awaiting re-initialization\n",
> > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > + }
> > + return true;
> > }
> >
> > static u64 csnow_mid;
> > @@ -356,6 +368,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > int next_cpu, reset_pending;
> > int64_t wd_nsec, cs_nsec;
> > struct clocksource *cs;
> > + bool coarse;
> > u32 md;
> >
> > spin_lock(&watchdog_lock);
> > @@ -373,16 +386,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > continue;
> > }
> >
> > - if (!cs_watchdog_read(cs, &csnow, &wdnow)) {
> > - /* Clock readout unreliable, so give it up. */
> > - __clocksource_unstable(cs);
> > - continue;
> > - }
> > + coarse = cs_watchdog_read(cs, &csnow, &wdnow);
> >
> > /* Clocksource initialized ? */
> > if (!(cs->flags & CLOCK_SOURCE_WATCHDOG) ||
> > atomic_read(&watchdog_reset_pending)) {
> > - cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > + if (!coarse)
> > + cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > cs->wd_last = wdnow;
> > cs->cs_last = csnow;
> > continue;
> > @@ -403,7 +413,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > continue;
> >
> > /* Check the deviation from the watchdog clocksource. */
> > - md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > + if (coarse) {
> > + md = 62500 * NSEC_PER_USEC;
> > + cs->flags &= ~CLOCK_SOURCE_WATCHDOG;
> > + pr_warn("timekeeping watchdog on CPU%d: %s coarse-grained %lu.%03lu ms clock-skew check followed by re-initialization\n", smp_processor_id(), watchdog->name, md / NSEC_PER_MSEC, md % NSEC_PER_MSEC / NSEC_PER_USEC);
> > + } else {
> > + md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > + }
> > if (abs(cs_nsec - wd_nsec) > md) {
> > pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as unstable because the skew is too large:\n",
> > smp_processor_id(), cs->name);

2021-11-03 08:28:04

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Mon, Nov 1, 2021 at 12:57 PM Paul E. McKenney <[email protected]> wrote:
>
> On Mon, Nov 01, 2021 at 05:59:52AM -0400, Luming Yu wrote:
> > On Fri, Oct 22, 2021 at 7:36 PM Paul E. McKenney <[email protected]> wrote:
> > >
> > > On Thu, Oct 21, 2021 at 05:37:24AM -0400, Luming Yu wrote:
> > > > On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
> > > > >
> > > > > On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > > > > > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > > > > > >
> > > > > > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > > > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > > > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > > > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > > > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > > > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > > > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > > > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > > > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > > > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > > > > > >>>> verification? Do you think this idea is okay?
> > > > > > > > >>>
> > > > > > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > > > > > >>>
> > > > > > > > >>
> > > > > > > > >> Sorry, it looks almost as follows:
> > > > > > > > >>
> > > > > > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > > > > >> index b8a14d2..87f3b67 100644
> > > > > > > > >> --- a/kernel/time/clocksource.c
> > > > > > > > >> +++ b/kernel/time/clocksource.c
> > > > > > > > >> @@ -119,6 +119,7 @@
> > > > > > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > > > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > > > > > >> static int watchdog_running;
> > > > > > > > >> +static unsigned long watchdog_start_time;
> > > > > > > > >> static atomic_t watchdog_reset_pending;
> > > > > > > > >>
> > > > > > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > > > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > > >> int next_cpu, reset_pending;
> > > > > > > > >> int64_t wd_nsec, cs_nsec;
> > > > > > > > >> struct clocksource *cs;
> > > > > > > > >> + unsigned long max_jiffies;
> > > > > > > > >> u32 md;
> > > > > > > > >>
> > > > > > > > >> spin_lock(&watchdog_lock);
> > > > > > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > > > > > >> continue;
> > > > > > > > >>
> > > > > > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > > > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > > > > > >> + continue;
> > > > > > > > >> +
> > > > > > > > >
> > > > > > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > > > > > updated by counting the number of tick intervals on the current
> > > > > > > > > clocksource.
> > > > > > > > >
> > > > > > > > > This seems like circular logic, where we're trying to judge the
> > > > > > > > > current clocksource by using something we derived from the current
> > > > > > > > > clocksource.
> > > > > > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > > > > > the preferred clocksource.
> > > > > > > > >
> > > > > > > > > So I'm not really sure how this helps.
> > > > > > > > >
> > > > > > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > > > > > being delayed) we have a better signal that the watchdog and current
> > > > > > > > > clocksource are out of sync. Because again, timers are fired based on
> > > > > > > >
> > > > > > > > I think only have a signal ls not enough. we need to prevent
> > > > > > > > clocksource from being incorrectly switched.
> > > > > > >
> > > > > > > Right, but we also have to ensure that we also properly disqualify
> > > > > > > clocksources that are misbehaving.
> > > > > > >
> > > > > > > In the case that the current clocksource is running very slow (imagine
> > > > > > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > > > > > so timers fire late.
> > > > > > > So it would constantly seem like the irqs are being delayed, so with
> > > > > > > your logic we would not disqualify a clearly malfunctioning
> > > > > > > clocksource..
> > > > > > >
> > > > > > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > > > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > > > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > > > > > will be delay executed.
> > > > > > >
> > > > > > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > > > > > want a short burst of timer misbehavior to disqualify a good
> > > > > > > clocksource.
> > > > > > >
> > > > > > > But the problem is that this situation and the one above (with the
> > > > > > > freq changing TSC), will look exactly the same.
> > > > > > >
> > > > > > > So having a situation where if the watchdog clocksource thinks too
> > > > > > > much time has passed between watchdog timers, we can skip judgement,
> > > > > > > assuming its a spurious delay. But I think we need to keep a counter
> > > > > > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > > > > > misbehavior and judge the current clocksource, as it may be running
> > > > > > > slowly.
> > > > > > >
> > > > > > > > >
> > > > > > > > I think it will be better to add this to my patch:
> > > > > > > > /*
> > > > > > > > * Interval: 0.5sec.
> > > > > > > > - * MaxInterval: 1s.
> > > > > > > > + * MaxInterval: 20s.
> > > > > > > > */
> > > > > > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > > > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > > > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > > > > > >
> > > > > > >
> > > > > > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > > > > > is a good idea.
> > > > > > >
> > > > > > > The other proposal to calculate the error rate, rather than a fixed
> > > > > > > error boundary might be useful too, as if the current clocksource and
> > > > > > > watchdog are close, a long timer delay won't disqualify them if we
> > > > > > > scale the error bounds to be within an given error rate.
> > > > > >
> > > > > > In most of tsc unstable trouble shooting on modern servers we experienced,
> > > > > > it usually ends up in a false alarm triggered by the clock source
> > > > > > watchdog for tsc.
> > > > > >
> > > > > > I think Paul has a proposal to make a clock source watchdog to be more
> > > > > > intelligent.
> > > > > > Its job is to find a real problem instead of causing a problem.
> > > > >
> > > > > And that proposal is now in mainline:
> > > >
> > > > Great! : -)
> > > > >
> > > > > 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> > > > > 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> > > > > 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> > > > > fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> > > > > 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> > > > > db3a34e17433 clocksource: Retry clock read if long delays detected
> > > > >
> > > > > The strategy is to disqualify a clock comparison if the reads took too
> > > > > long, and to retry the comparison. If four consecutive comparison take
> > > > > too long, clock skew is reported. The number of consecutive comparisons
> > > > > may be adjusted by the usual kernel boot parameter.
> > > > >
> > > > > > so disabling it for known good-tsc might be a reasonable good idea
> > > > > > that can save manpower for other
> > > > > > more valuable problems to solve, or at least make it statistically a
> > > > > > problem less chance to happen.
> > > > >
> > > > > One additional piece that is still in prototype state in -rcu is to give
> > > > > clocksources some opportunity to resynchronize if there are too many
> > > > > slow comparisons. This is intended to handle cases where clocks often
> > > >
> > > > if there is such tsc-sync algorithm existing in software, it really
> > > > can help system software engineers
> > > > to solve some rare power good signals synchronization problem caused
> > > > by bios that caused
> > > > boot time tsc sync check failure that usually would consume huge
> > > > debugging engine for bringing up qualified linux system.
> > > >
> > > > Less depending on platform quirks should be good thing to linux for
> > > > tsc && rcu support.
> > >
> > > Good point, I have procrastinated long enough.
> > >
> > > How about like this?
> >
> > sorry, I meant a better algorithm to use tsc adjust register
> > like the tried one in arch/x86/kernel/tsc_sync.c
>
> Ah, at this time I must leave that sort of task to others.

sure.
if anyone is still debugging clock-source watchdog issue, It is
highly appreciated and would be more helpful to others
that we truly need to decouple TSC with slow clock source.
we need to be aware of that when looking into clock source watchdog issues.

And many thanks to the value of your patch, I 'm seeing another report
that obviously has carried "attempt 4, marking unstable"
one or two times at the beginning followed less occurrence after
hundreds of boot..
： high priority --> medium

>
> Thanx, Paul
>
> > > ------------------------------------------------------------------------
> > >
> > > commit 9ec2a03bbf4bee3d9fbc02a402dee36efafc5a2d
> > > Author: Paul E. McKenney <[email protected]>
> > > Date: Thu May 27 11:03:28 2021 -0700
> > >
> > > clocksource: Forgive repeated long-latency watchdog clocksource reads
> > >
> > > Currently, the clocksource watchdog reacts to repeated long-latency
> > > clocksource reads by marking that clocksource unstable on the theory that
> > > these long-latency reads are a sign of a serious problem. And this theory
> >
> > Maybe we need to use other core's tsc as a reference clock instead of
> > using HPET, which , to my knowledge , is the place where the problem happens.
> >
> > Ruling out HPET and other slow clock devices as the obvious wrong choice
> > of a reference clock for tsc, I guess there will be less chance we
> > (in kernel code)
> > will get bothered by other latency problems perceived in the clock
> > source watchdog.
>
> There have been a number of patches that identify systems that tend to
> have unreliable HPET implementations. Perhaps more systems are needed
> there, or maybe some of those patches need to be backported to the
> version of Linux that you are using.
>
> There was also a patch that identified systems that are expected to have
> reliable TSCs, and that de-emphasized HPET on such systems.
>
> Thanx, Paul
>
> > > does in fact have real-world support in the form of firmware issues [1].
> > >
> > > However, it is also possible to trigger this using stress-ng on what
> > > the stress-ng man page terms "poorly designed hardware" [2]. And it
> > > is not necessarily a bad thing for the kernel to diagnose cases where
> > > heavy memory-contention workloads are being run on hardware that is not
> > > designed for this sort of use.
> > >
> > > Nevertheless, it is quite possible that real-world use will result in
> > > some situation requiring that high-stress workloads run on hardware
> > > not designed to accommodate them, and also requiring that the kernel
> > > refrain from marking clocksources unstable.
> > >
> > > Therefore, react to persistent long-latency reads by leaving the
> > > clocksource alone, but using the old 62.5-millisecond skew-detection
> > > threshold. In addition, the offending clocksource is marked for
> > > re-initialization, which both restarts that clocksource with a clean bill
> > > of health and avoids false-positive skew reports on later watchdog checks.
> > > Once marked for re-initialization, the clocksource is not subjected to
> > > further watchdog checking until a subsequent successful read from that
> > > clocksource that is free of excessive delays.
> > >
> > > However, if clocksource.max_cswd_coarse_reads consecutive clocksource read
> > > attempts result in long latencies, a warning (splat) will be emitted.
> > > This kernel boot parameter defaults to 100, and this warning can be
> > > disabled by setting it to zero or to a negative value.
> > >
> > > [ paulmck: Apply feedback from Chao Gao ]
> > >
> > > Link: https://lore.kernel.org/lkml/20210513155515.GB23902@xsang-OptiPlex-9020/ # [1]
> > > Link: https://lore.kernel.org/lkml/20210521083322.GG25531@xsang-OptiPlex-9020/ # [2]
> > > Link: https://lore.kernel.org/lkml/20210521084405.GH25531@xsang-OptiPlex-9020/
> > > Link: https://lore.kernel.org/lkml/20210511233403.GA2896757@paulmck-ThinkPad-P17-Gen-1/
> > > Tested-by: Chao Gao <[email protected]>
> > > Signed-off-by: Paul E. McKenney <[email protected]>
> > >
> > > diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> > > index 316027c3aadc..61d2436ae9df 100644
> > > --- a/Documentation/admin-guide/kernel-parameters.txt
> > > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > > @@ -600,6 +600,14 @@
> > > loops can be debugged more effectively on production
> > > systems.
> > >
> > > + clocksource.max_cswd_coarse_reads= [KNL]
> > > + Number of consecutive clocksource_watchdog()
> > > + coarse reads (that is, clocksource reads that
> > > + were unduly delayed) that are permitted before
> > > + the kernel complains (gently). Set to a value
> > > + less than or equal to zero to suppress these
> > > + complaints.
> > > +
> > > clocksource.max_cswd_read_retries= [KNL]
> > > Number of clocksource_watchdog() retries due to
> > > external delays before the clock will be marked
> > > diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
> > > index 1d42d4b17327..3e925d9ffc31 100644
> > > --- a/include/linux/clocksource.h
> > > +++ b/include/linux/clocksource.h
> > > @@ -110,6 +110,7 @@ struct clocksource {
> > > int rating;
> > > enum clocksource_ids id;
> > > enum vdso_clock_mode vdso_clock_mode;
> > > + unsigned int n_coarse_reads;
> > > unsigned long flags;
> > >
> > > int (*enable)(struct clocksource *cs);
> > > @@ -291,6 +292,7 @@ static inline void timer_probe(void) {}
> > > #define TIMER_ACPI_DECLARE(name, table_id, fn) \
> > > ACPI_DECLARE_PROBE_ENTRY(timer, name, table_id, 0, NULL, 0, fn)
> > >
> > > +extern int max_cswd_coarse_reads;
> > > extern ulong max_cswd_read_retries;
> > > void clocksource_verify_percpu(struct clocksource *cs);
> > >
> > > diff --git a/kernel/time/clocksource-wdtest.c b/kernel/time/clocksource-wdtest.c
> > > index df922f49d171..7e82500c400b 100644
> > > --- a/kernel/time/clocksource-wdtest.c
> > > +++ b/kernel/time/clocksource-wdtest.c
> > > @@ -145,13 +145,12 @@ static int wdtest_func(void *arg)
> > > else if (i <= max_cswd_read_retries)
> > > s = ", expect message";
> > > else
> > > - s = ", expect clock skew";
> > > + s = ", expect coarse-grained clock skew check and re-initialization";
> > > pr_info("--- Watchdog with %dx error injection, %lu retries%s.\n", i, max_cswd_read_retries, s);
> > > WRITE_ONCE(wdtest_ktime_read_ndelays, i);
> > > schedule_timeout_uninterruptible(2 * HZ);
> > > WARN_ON_ONCE(READ_ONCE(wdtest_ktime_read_ndelays));
> > > - WARN_ON_ONCE((i <= max_cswd_read_retries) !=
> > > - !(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE));
> > > + WARN_ON_ONCE(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE);
> > > wdtest_ktime_clocksource_reset();
> > > }
> > >
> > > diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > index b8a14d2fb5ba..796a127aabb9 100644
> > > --- a/kernel/time/clocksource.c
> > > +++ b/kernel/time/clocksource.c
> > > @@ -199,6 +199,9 @@ void clocksource_mark_unstable(struct clocksource *cs)
> > > spin_unlock_irqrestore(&watchdog_lock, flags);
> > > }
> > >
> > > +int max_cswd_coarse_reads = 100;
> > > +module_param(max_cswd_coarse_reads, int, 0644);
> > > +EXPORT_SYMBOL_GPL(max_cswd_coarse_reads);
> > > ulong max_cswd_read_retries = 3;
> > > module_param(max_cswd_read_retries, ulong, 0644);
> > > EXPORT_SYMBOL_GPL(max_cswd_read_retries);
> > > @@ -226,13 +229,22 @@ static bool cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
> > > pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
> > > smp_processor_id(), watchdog->name, nretries);
> > > }
> > > - return true;
> > > + cs->n_coarse_reads = 0;
> > > + return false;
> > > }
> > > + WARN_ONCE(max_cswd_coarse_reads > 0 &&
> > > + !(++cs->n_coarse_reads % max_cswd_coarse_reads),
> > > + "timekeeping watchdog on CPU%d: %s %u consecutive coarse-grained reads\n", smp_processor_id(), watchdog->name, cs->n_coarse_reads);
> > > }
> > >
> > > - pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, marking unstable\n",
> > > - smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > - return false;
> > > + if ((cs->flags & CLOCK_SOURCE_WATCHDOG) && !atomic_read(&watchdog_reset_pending)) {
> > > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, coarse-grained skew check followed by re-initialization\n",
> > > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > + } else {
> > > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, awaiting re-initialization\n",
> > > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > + }
> > > + return true;
> > > }
> > >
> > > static u64 csnow_mid;
> > > @@ -356,6 +368,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > int next_cpu, reset_pending;
> > > int64_t wd_nsec, cs_nsec;
> > > struct clocksource *cs;
> > > + bool coarse;
> > > u32 md;
> > >
> > > spin_lock(&watchdog_lock);
> > > @@ -373,16 +386,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > continue;
> > > }
> > >
> > > - if (!cs_watchdog_read(cs, &csnow, &wdnow)) {
> > > - /* Clock readout unreliable, so give it up. */
> > > - __clocksource_unstable(cs);
> > > - continue;
> > > - }
> > > + coarse = cs_watchdog_read(cs, &csnow, &wdnow);
> > >
> > > /* Clocksource initialized ? */
> > > if (!(cs->flags & CLOCK_SOURCE_WATCHDOG) ||
> > > atomic_read(&watchdog_reset_pending)) {
> > > - cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > > + if (!coarse)
> > > + cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > > cs->wd_last = wdnow;
> > > cs->cs_last = csnow;
> > > continue;
> > > @@ -403,7 +413,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > continue;
> > >
> > > /* Check the deviation from the watchdog clocksource. */
> > > - md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > > + if (coarse) {
> > > + md = 62500 * NSEC_PER_USEC;
> > > + cs->flags &= ~CLOCK_SOURCE_WATCHDOG;
> > > + pr_warn("timekeeping watchdog on CPU%d: %s coarse-grained %lu.%03lu ms clock-skew check followed by re-initialization\n", smp_processor_id(), watchdog->name, md / NSEC_PER_MSEC, md % NSEC_PER_MSEC / NSEC_PER_USEC);
> > > + } else {
> > > + md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > > + }
> > > if (abs(cs_nsec - wd_nsec) > md) {
> > > pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as unstable because the skew is too large:\n",
> > > smp_processor_id(), cs->name);

2021-11-03 15:55:56

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Wed, Nov 03, 2021 at 04:27:42AM -0400, Luming Yu wrote:
> On Mon, Nov 1, 2021 at 12:57 PM Paul E. McKenney <[email protected]> wrote:
> >
> > On Mon, Nov 01, 2021 at 05:59:52AM -0400, Luming Yu wrote:
> > > On Fri, Oct 22, 2021 at 7:36 PM Paul E. McKenney <[email protected]> wrote:
> > > >
> > > > On Thu, Oct 21, 2021 at 05:37:24AM -0400, Luming Yu wrote:
> > > > > On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
> > > > > >
> > > > > > On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > > > > > > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > > > > > > >
> > > > > > > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > > > > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > > > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > > > > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > > > > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > > > > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > > > > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > > > > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > > > > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > > > > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > > > > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > > > > > > >>>> verification? Do you think this idea is okay?
> > > > > > > > > >>>
> > > > > > > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > > > > > > >>>
> > > > > > > > > >>
> > > > > > > > > >> Sorry, it looks almost as follows:
> > > > > > > > > >>
> > > > > > > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > > > > > >> index b8a14d2..87f3b67 100644
> > > > > > > > > >> --- a/kernel/time/clocksource.c
> > > > > > > > > >> +++ b/kernel/time/clocksource.c
> > > > > > > > > >> @@ -119,6 +119,7 @@
> > > > > > > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > > > > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > > > > > > >> static int watchdog_running;
> > > > > > > > > >> +static unsigned long watchdog_start_time;
> > > > > > > > > >> static atomic_t watchdog_reset_pending;
> > > > > > > > > >>
> > > > > > > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > > > > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > > > >> int next_cpu, reset_pending;
> > > > > > > > > >> int64_t wd_nsec, cs_nsec;
> > > > > > > > > >> struct clocksource *cs;
> > > > > > > > > >> + unsigned long max_jiffies;
> > > > > > > > > >> u32 md;
> > > > > > > > > >>
> > > > > > > > > >> spin_lock(&watchdog_lock);
> > > > > > > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > > > > > > >> continue;
> > > > > > > > > >>
> > > > > > > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > > > > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > > > > > > >> + continue;
> > > > > > > > > >> +
> > > > > > > > > >
> > > > > > > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > > > > > > updated by counting the number of tick intervals on the current
> > > > > > > > > > clocksource.
> > > > > > > > > >
> > > > > > > > > > This seems like circular logic, where we're trying to judge the
> > > > > > > > > > current clocksource by using something we derived from the current
> > > > > > > > > > clocksource.
> > > > > > > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > > > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > > > > > > the preferred clocksource.
> > > > > > > > > >
> > > > > > > > > > So I'm not really sure how this helps.
> > > > > > > > > >
> > > > > > > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > > > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > > > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > > > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > > > > > > being delayed) we have a better signal that the watchdog and current
> > > > > > > > > > clocksource are out of sync. Because again, timers are fired based on
> > > > > > > > >
> > > > > > > > > I think only have a signal ls not enough. we need to prevent
> > > > > > > > > clocksource from being incorrectly switched.
> > > > > > > >
> > > > > > > > Right, but we also have to ensure that we also properly disqualify
> > > > > > > > clocksources that are misbehaving.
> > > > > > > >
> > > > > > > > In the case that the current clocksource is running very slow (imagine
> > > > > > > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > > > > > > so timers fire late.
> > > > > > > > So it would constantly seem like the irqs are being delayed, so with
> > > > > > > > your logic we would not disqualify a clearly malfunctioning
> > > > > > > > clocksource..
> > > > > > > >
> > > > > > > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > > > > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > > > > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > > > > > > will be delay executed.
> > > > > > > >
> > > > > > > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > > > > > > want a short burst of timer misbehavior to disqualify a good
> > > > > > > > clocksource.
> > > > > > > >
> > > > > > > > But the problem is that this situation and the one above (with the
> > > > > > > > freq changing TSC), will look exactly the same.
> > > > > > > >
> > > > > > > > So having a situation where if the watchdog clocksource thinks too
> > > > > > > > much time has passed between watchdog timers, we can skip judgement,
> > > > > > > > assuming its a spurious delay. But I think we need to keep a counter
> > > > > > > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > > > > > > misbehavior and judge the current clocksource, as it may be running
> > > > > > > > slowly.
> > > > > > > >
> > > > > > > > > >
> > > > > > > > > I think it will be better to add this to my patch:
> > > > > > > > > /*
> > > > > > > > > * Interval: 0.5sec.
> > > > > > > > > - * MaxInterval: 1s.
> > > > > > > > > + * MaxInterval: 20s.
> > > > > > > > > */
> > > > > > > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > > > > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > > > > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > > > > > > >
> > > > > > > >
> > > > > > > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > > > > > > is a good idea.
> > > > > > > >
> > > > > > > > The other proposal to calculate the error rate, rather than a fixed
> > > > > > > > error boundary might be useful too, as if the current clocksource and
> > > > > > > > watchdog are close, a long timer delay won't disqualify them if we
> > > > > > > > scale the error bounds to be within an given error rate.
> > > > > > >
> > > > > > > In most of tsc unstable trouble shooting on modern servers we experienced,
> > > > > > > it usually ends up in a false alarm triggered by the clock source
> > > > > > > watchdog for tsc.
> > > > > > >
> > > > > > > I think Paul has a proposal to make a clock source watchdog to be more
> > > > > > > intelligent.
> > > > > > > Its job is to find a real problem instead of causing a problem.
> > > > > >
> > > > > > And that proposal is now in mainline:
> > > > >
> > > > > Great! : -)
> > > > > >
> > > > > > 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> > > > > > 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> > > > > > 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> > > > > > fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> > > > > > 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> > > > > > db3a34e17433 clocksource: Retry clock read if long delays detected
> > > > > >
> > > > > > The strategy is to disqualify a clock comparison if the reads took too
> > > > > > long, and to retry the comparison. If four consecutive comparison take
> > > > > > too long, clock skew is reported. The number of consecutive comparisons
> > > > > > may be adjusted by the usual kernel boot parameter.
> > > > > >
> > > > > > > so disabling it for known good-tsc might be a reasonable good idea
> > > > > > > that can save manpower for other
> > > > > > > more valuable problems to solve, or at least make it statistically a
> > > > > > > problem less chance to happen.
> > > > > >
> > > > > > One additional piece that is still in prototype state in -rcu is to give
> > > > > > clocksources some opportunity to resynchronize if there are too many
> > > > > > slow comparisons. This is intended to handle cases where clocks often
> > > > >
> > > > > if there is such tsc-sync algorithm existing in software, it really
> > > > > can help system software engineers
> > > > > to solve some rare power good signals synchronization problem caused
> > > > > by bios that caused
> > > > > boot time tsc sync check failure that usually would consume huge
> > > > > debugging engine for bringing up qualified linux system.
> > > > >
> > > > > Less depending on platform quirks should be good thing to linux for
> > > > > tsc && rcu support.
> > > >
> > > > Good point, I have procrastinated long enough.
> > > >
> > > > How about like this?
> > >
> > > sorry, I meant a better algorithm to use tsc adjust register
> > > like the tried one in arch/x86/kernel/tsc_sync.c
> >
> > Ah, at this time I must leave that sort of task to others.
>
> sure.
> if anyone is still debugging clock-source watchdog issue, It is
> highly appreciated and would be more helpful to others
> that we truly need to decouple TSC with slow clock source.
> we need to be aware of that when looking into clock source watchdog issues.

There is a old saying that those with only one clock always know what
time it is, but those with more than one clock never can be sure. ;-)

In the testing and validation phases, one should supply a known good
external clock against which to check everything. I could imagine doing
something similar in production using any of a number of Internet time
services, but that project is beyond what I can commit to any time soon.
Note that it is not so simple because it must deal with arbitrary delays
across the Internet, the possibility of broken Internet time services,
and so on.

But in the common case, I bet it would greatly simplify your debugging
efforts!

> And many thanks to the value of your patch, I 'm seeing another report
> that obviously has carried "attempt 4, marking unstable"
> one or two times at the beginning followed less occurrence after
> hundreds of boot..
> ： high priority --> medium

I am glad that it helped!

Thanx, Paul

> > > > ------------------------------------------------------------------------
> > > >
> > > > commit 9ec2a03bbf4bee3d9fbc02a402dee36efafc5a2d
> > > > Author: Paul E. McKenney <[email protected]>
> > > > Date: Thu May 27 11:03:28 2021 -0700
> > > >
> > > > clocksource: Forgive repeated long-latency watchdog clocksource reads
> > > >
> > > > Currently, the clocksource watchdog reacts to repeated long-latency
> > > > clocksource reads by marking that clocksource unstable on the theory that
> > > > these long-latency reads are a sign of a serious problem. And this theory
> > >
> > > Maybe we need to use other core's tsc as a reference clock instead of
> > > using HPET, which , to my knowledge , is the place where the problem happens.
> > >
> > > Ruling out HPET and other slow clock devices as the obvious wrong choice
> > > of a reference clock for tsc, I guess there will be less chance we
> > > (in kernel code)
> > > will get bothered by other latency problems perceived in the clock
> > > source watchdog.
> >
> > There have been a number of patches that identify systems that tend to
> > have unreliable HPET implementations. Perhaps more systems are needed
> > there, or maybe some of those patches need to be backported to the
> > version of Linux that you are using.
> >
> > There was also a patch that identified systems that are expected to have
> > reliable TSCs, and that de-emphasized HPET on such systems.
> >
> > Thanx, Paul
> >
> > > > does in fact have real-world support in the form of firmware issues [1].
> > > >
> > > > However, it is also possible to trigger this using stress-ng on what
> > > > the stress-ng man page terms "poorly designed hardware" [2]. And it
> > > > is not necessarily a bad thing for the kernel to diagnose cases where
> > > > heavy memory-contention workloads are being run on hardware that is not
> > > > designed for this sort of use.
> > > >
> > > > Nevertheless, it is quite possible that real-world use will result in
> > > > some situation requiring that high-stress workloads run on hardware
> > > > not designed to accommodate them, and also requiring that the kernel
> > > > refrain from marking clocksources unstable.
> > > >
> > > > Therefore, react to persistent long-latency reads by leaving the
> > > > clocksource alone, but using the old 62.5-millisecond skew-detection
> > > > threshold. In addition, the offending clocksource is marked for
> > > > re-initialization, which both restarts that clocksource with a clean bill
> > > > of health and avoids false-positive skew reports on later watchdog checks.
> > > > Once marked for re-initialization, the clocksource is not subjected to
> > > > further watchdog checking until a subsequent successful read from that
> > > > clocksource that is free of excessive delays.
> > > >
> > > > However, if clocksource.max_cswd_coarse_reads consecutive clocksource read
> > > > attempts result in long latencies, a warning (splat) will be emitted.
> > > > This kernel boot parameter defaults to 100, and this warning can be
> > > > disabled by setting it to zero or to a negative value.
> > > >
> > > > [ paulmck: Apply feedback from Chao Gao ]
> > > >
> > > > Link: https://lore.kernel.org/lkml/20210513155515.GB23902@xsang-OptiPlex-9020/ # [1]
> > > > Link: https://lore.kernel.org/lkml/20210521083322.GG25531@xsang-OptiPlex-9020/ # [2]
> > > > Link: https://lore.kernel.org/lkml/20210521084405.GH25531@xsang-OptiPlex-9020/
> > > > Link: https://lore.kernel.org/lkml/20210511233403.GA2896757@paulmck-ThinkPad-P17-Gen-1/
> > > > Tested-by: Chao Gao <[email protected]>
> > > > Signed-off-by: Paul E. McKenney <[email protected]>
> > > >
> > > > diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> > > > index 316027c3aadc..61d2436ae9df 100644
> > > > --- a/Documentation/admin-guide/kernel-parameters.txt
> > > > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > > > @@ -600,6 +600,14 @@
> > > > loops can be debugged more effectively on production
> > > > systems.
> > > >
> > > > + clocksource.max_cswd_coarse_reads= [KNL]
> > > > + Number of consecutive clocksource_watchdog()
> > > > + coarse reads (that is, clocksource reads that
> > > > + were unduly delayed) that are permitted before
> > > > + the kernel complains (gently). Set to a value
> > > > + less than or equal to zero to suppress these
> > > > + complaints.
> > > > +
> > > > clocksource.max_cswd_read_retries= [KNL]
> > > > Number of clocksource_watchdog() retries due to
> > > > external delays before the clock will be marked
> > > > diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
> > > > index 1d42d4b17327..3e925d9ffc31 100644
> > > > --- a/include/linux/clocksource.h
> > > > +++ b/include/linux/clocksource.h
> > > > @@ -110,6 +110,7 @@ struct clocksource {
> > > > int rating;
> > > > enum clocksource_ids id;
> > > > enum vdso_clock_mode vdso_clock_mode;
> > > > + unsigned int n_coarse_reads;
> > > > unsigned long flags;
> > > >
> > > > int (*enable)(struct clocksource *cs);
> > > > @@ -291,6 +292,7 @@ static inline void timer_probe(void) {}
> > > > #define TIMER_ACPI_DECLARE(name, table_id, fn) \
> > > > ACPI_DECLARE_PROBE_ENTRY(timer, name, table_id, 0, NULL, 0, fn)
> > > >
> > > > +extern int max_cswd_coarse_reads;
> > > > extern ulong max_cswd_read_retries;
> > > > void clocksource_verify_percpu(struct clocksource *cs);
> > > >
> > > > diff --git a/kernel/time/clocksource-wdtest.c b/kernel/time/clocksource-wdtest.c
> > > > index df922f49d171..7e82500c400b 100644
> > > > --- a/kernel/time/clocksource-wdtest.c
> > > > +++ b/kernel/time/clocksource-wdtest.c
> > > > @@ -145,13 +145,12 @@ static int wdtest_func(void *arg)
> > > > else if (i <= max_cswd_read_retries)
> > > > s = ", expect message";
> > > > else
> > > > - s = ", expect clock skew";
> > > > + s = ", expect coarse-grained clock skew check and re-initialization";
> > > > pr_info("--- Watchdog with %dx error injection, %lu retries%s.\n", i, max_cswd_read_retries, s);
> > > > WRITE_ONCE(wdtest_ktime_read_ndelays, i);
> > > > schedule_timeout_uninterruptible(2 * HZ);
> > > > WARN_ON_ONCE(READ_ONCE(wdtest_ktime_read_ndelays));
> > > > - WARN_ON_ONCE((i <= max_cswd_read_retries) !=
> > > > - !(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE));
> > > > + WARN_ON_ONCE(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE);
> > > > wdtest_ktime_clocksource_reset();
> > > > }
> > > >
> > > > diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > index b8a14d2fb5ba..796a127aabb9 100644
> > > > --- a/kernel/time/clocksource.c
> > > > +++ b/kernel/time/clocksource.c
> > > > @@ -199,6 +199,9 @@ void clocksource_mark_unstable(struct clocksource *cs)
> > > > spin_unlock_irqrestore(&watchdog_lock, flags);
> > > > }
> > > >
> > > > +int max_cswd_coarse_reads = 100;
> > > > +module_param(max_cswd_coarse_reads, int, 0644);
> > > > +EXPORT_SYMBOL_GPL(max_cswd_coarse_reads);
> > > > ulong max_cswd_read_retries = 3;
> > > > module_param(max_cswd_read_retries, ulong, 0644);
> > > > EXPORT_SYMBOL_GPL(max_cswd_read_retries);
> > > > @@ -226,13 +229,22 @@ static bool cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
> > > > pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
> > > > smp_processor_id(), watchdog->name, nretries);
> > > > }
> > > > - return true;
> > > > + cs->n_coarse_reads = 0;
> > > > + return false;
> > > > }
> > > > + WARN_ONCE(max_cswd_coarse_reads > 0 &&
> > > > + !(++cs->n_coarse_reads % max_cswd_coarse_reads),
> > > > + "timekeeping watchdog on CPU%d: %s %u consecutive coarse-grained reads\n", smp_processor_id(), watchdog->name, cs->n_coarse_reads);
> > > > }
> > > >
> > > > - pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, marking unstable\n",
> > > > - smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > > - return false;
> > > > + if ((cs->flags & CLOCK_SOURCE_WATCHDOG) && !atomic_read(&watchdog_reset_pending)) {
> > > > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, coarse-grained skew check followed by re-initialization\n",
> > > > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > > + } else {
> > > > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, awaiting re-initialization\n",
> > > > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > > + }
> > > > + return true;
> > > > }
> > > >
> > > > static u64 csnow_mid;
> > > > @@ -356,6 +368,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > int next_cpu, reset_pending;
> > > > int64_t wd_nsec, cs_nsec;
> > > > struct clocksource *cs;
> > > > + bool coarse;
> > > > u32 md;
> > > >
> > > > spin_lock(&watchdog_lock);
> > > > @@ -373,16 +386,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > continue;
> > > > }
> > > >
> > > > - if (!cs_watchdog_read(cs, &csnow, &wdnow)) {
> > > > - /* Clock readout unreliable, so give it up. */
> > > > - __clocksource_unstable(cs);
> > > > - continue;
> > > > - }
> > > > + coarse = cs_watchdog_read(cs, &csnow, &wdnow);
> > > >
> > > > /* Clocksource initialized ? */
> > > > if (!(cs->flags & CLOCK_SOURCE_WATCHDOG) ||
> > > > atomic_read(&watchdog_reset_pending)) {
> > > > - cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > > > + if (!coarse)
> > > > + cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > > > cs->wd_last = wdnow;
> > > > cs->cs_last = csnow;
> > > > continue;
> > > > @@ -403,7 +413,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > continue;
> > > >
> > > > /* Check the deviation from the watchdog clocksource. */
> > > > - md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > > > + if (coarse) {
> > > > + md = 62500 * NSEC_PER_USEC;
> > > > + cs->flags &= ~CLOCK_SOURCE_WATCHDOG;
> > > > + pr_warn("timekeeping watchdog on CPU%d: %s coarse-grained %lu.%03lu ms clock-skew check followed by re-initialization\n", smp_processor_id(), watchdog->name, md / NSEC_PER_MSEC, md % NSEC_PER_MSEC / NSEC_PER_USEC);
> > > > + } else {
> > > > + md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > > > + }
> > > > if (abs(cs_nsec - wd_nsec) > md) {
> > > > pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as unstable because the skew is too large:\n",
> > > > smp_processor_id(), cs->name);

2021-11-04 10:58:58

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

On Wed, Nov 3, 2021 at 11:54 PM Paul E. McKenney <[email protected]> wrote:
>
> On Wed, Nov 03, 2021 at 04:27:42AM -0400, Luming Yu wrote:
> > On Mon, Nov 1, 2021 at 12:57 PM Paul E. McKenney <[email protected]> wrote:
> > >
> > > On Mon, Nov 01, 2021 at 05:59:52AM -0400, Luming Yu wrote:
> > > > On Fri, Oct 22, 2021 at 7:36 PM Paul E. McKenney <[email protected]> wrote:
> > > > >
> > > > > On Thu, Oct 21, 2021 at 05:37:24AM -0400, Luming Yu wrote:
> > > > > > On Wed, Oct 20, 2021 at 1:49 PM Paul E. McKenney <[email protected]> wrote:
> > > > > > >
> > > > > > > On Wed, Oct 20, 2021 at 06:09:58AM -0400, Luming Yu wrote:
> > > > > > > > On Tue, Oct 19, 2021 at 1:04 AM John Stultz <[email protected]> wrote:
> > > > > > > > >
> > > > > > > > > On Mon, Oct 18, 2021 at 9:14 PM yanghui <[email protected]> wrote:
> > > > > > > > > > 在 2021/10/19 上午12:14, John Stultz 写道:
> > > > > > > > > > > On Tue, Oct 12, 2021 at 1:06 AM brookxu <[email protected]> wrote:
> > > > > > > > > > >> John Stultz wrote on 2021/10/12 13:29:
> > > > > > > > > > >>> On Mon, Oct 11, 2021 at 10:23 PM brookxu <[email protected]> wrote:
> > > > > > > > > > >>>> John Stultz wrote on 2021/10/12 12:52 下午:
> > > > > > > > > > >>>>> On Sat, Oct 9, 2021 at 7:04 AM brookxu <[email protected]> wrote:
> > > > > > > > > > >>>> If we record the watchdog's start_time in clocksource_start_watchdog(), and then
> > > > > > > > > > >>>> when we verify cycles in clocksource_watchdog(), check whether the clocksource
> > > > > > > > > > >>>> watchdog is blocked. Due to MSB verification, if the blocked time is greater than
> > > > > > > > > > >>>> half of the watchdog timer max_cycles, then we can safely ignore the current
> > > > > > > > > > >>>> verification? Do you think this idea is okay?
> > > > > > > > > > >>>
> > > > > > > > > > >>> I can't say I totally understand the idea. Maybe could you clarify with a patch?
> > > > > > > > > > >>>
> > > > > > > > > > >>
> > > > > > > > > > >> Sorry, it looks almost as follows:
> > > > > > > > > > >>
> > > > > > > > > > >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > > > > > > >> index b8a14d2..87f3b67 100644
> > > > > > > > > > >> --- a/kernel/time/clocksource.c
> > > > > > > > > > >> +++ b/kernel/time/clocksource.c
> > > > > > > > > > >> @@ -119,6 +119,7 @@
> > > > > > > > > > >> static DECLARE_WORK(watchdog_work, clocksource_watchdog_work);
> > > > > > > > > > >> static DEFINE_SPINLOCK(watchdog_lock);
> > > > > > > > > > >> static int watchdog_running;
> > > > > > > > > > >> +static unsigned long watchdog_start_time;
> > > > > > > > > > >> static atomic_t watchdog_reset_pending;
> > > > > > > > > > >>
> > > > > > > > > > >> static inline void clocksource_watchdog_lock(unsigned long *flags)
> > > > > > > > > > >> @@ -356,6 +357,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > > > > >> int next_cpu, reset_pending;
> > > > > > > > > > >> int64_t wd_nsec, cs_nsec;
> > > > > > > > > > >> struct clocksource *cs;
> > > > > > > > > > >> + unsigned long max_jiffies;
> > > > > > > > > > >> u32 md;
> > > > > > > > > > >>
> > > > > > > > > > >> spin_lock(&watchdog_lock);
> > > > > > > > > > >> @@ -402,6 +404,10 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > > > > > > >> if (atomic_read(&watchdog_reset_pending))
> > > > > > > > > > >> continue;
> > > > > > > > > > >>
> > > > > > > > > > >> + max_jiffies = nsecs_to_jiffies(cs->max_idle_ns);
> > > > > > > > > > >> + if (time_is_before_jiffies(watchdog_start_time + max_jiffies))
> > > > > > > > > > >> + continue;
> > > > > > > > > > >> +
> > > > > > > > > > >
> > > > > > > > > > > Sorry, what is the benefit of using jiffies here? Jiffies are
> > > > > > > > > > > updated by counting the number of tick intervals on the current
> > > > > > > > > > > clocksource.
> > > > > > > > > > >
> > > > > > > > > > > This seems like circular logic, where we're trying to judge the
> > > > > > > > > > > current clocksource by using something we derived from the current
> > > > > > > > > > > clocksource.
> > > > > > > > > > > That's why the watchdog clocksource is important, as it's supposed to
> > > > > > > > > > > be a separate counter that is more reliable (but likely slower) then
> > > > > > > > > > > the preferred clocksource.
> > > > > > > > > > >
> > > > > > > > > > > So I'm not really sure how this helps.
> > > > > > > > > > >
> > > > > > > > > > > The earlier patch by yanghui at least used the watchdog interval to
> > > > > > > > > > > decide if the watchdog timer had expired late. Which seemed
> > > > > > > > > > > reasonable, but I thought it might be helpful to add some sort of a
> > > > > > > > > > > counter so if the case is happening repeatedly (timers constantly
> > > > > > > > > > > being delayed) we have a better signal that the watchdog and current
> > > > > > > > > > > clocksource are out of sync. Because again, timers are fired based on
> > > > > > > > > >
> > > > > > > > > > I think only have a signal ls not enough. we need to prevent
> > > > > > > > > > clocksource from being incorrectly switched.
> > > > > > > > >
> > > > > > > > > Right, but we also have to ensure that we also properly disqualify
> > > > > > > > > clocksources that are misbehaving.
> > > > > > > > >
> > > > > > > > > In the case that the current clocksource is running very slow (imagine
> > > > > > > > > old TSCs that lowered freq with cpufreq), then system time slows down,
> > > > > > > > > so timers fire late.
> > > > > > > > > So it would constantly seem like the irqs are being delayed, so with
> > > > > > > > > your logic we would not disqualify a clearly malfunctioning
> > > > > > > > > clocksource..
> > > > > > > > >
> > > > > > > > > > The Timer callback function clocksource_watchdog() is executed in the
> > > > > > > > > > context of softirq(run_timer_softirq()). So if softirq is disabled for
> > > > > > > > > > long time(One situation is long time softlockup), clocksource_watchdog()
> > > > > > > > > > will be delay executed.
> > > > > > > > >
> > > > > > > > > Yes. The reality is that timers are often spuriously delayed. We don't
> > > > > > > > > want a short burst of timer misbehavior to disqualify a good
> > > > > > > > > clocksource.
> > > > > > > > >
> > > > > > > > > But the problem is that this situation and the one above (with the
> > > > > > > > > freq changing TSC), will look exactly the same.
> > > > > > > > >
> > > > > > > > > So having a situation where if the watchdog clocksource thinks too
> > > > > > > > > much time has passed between watchdog timers, we can skip judgement,
> > > > > > > > > assuming its a spurious delay. But I think we need to keep a counter
> > > > > > > > > so that if this happens 3-5 times in a row, we stop ignoring the
> > > > > > > > > misbehavior and judge the current clocksource, as it may be running
> > > > > > > > > slowly.
> > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > > I think it will be better to add this to my patch:
> > > > > > > > > > /*
> > > > > > > > > > * Interval: 0.5sec.
> > > > > > > > > > - * MaxInterval: 1s.
> > > > > > > > > > + * MaxInterval: 20s.
> > > > > > > > > > */
> > > > > > > > > > #define WATCHDOG_INTERVAL (HZ >> 1)
> > > > > > > > > > -#define WATCHDOG_MAX_INTERVAL_NS (NSEC_PER_SEC)
> > > > > > > > > > +#define WATCHDOG_MAX_INTERVAL_NS (20 * NSEC_PER_SEC)
> > > > > > > > > >
> > > > > > > > >
> > > > > > > > > Some watchdog counters wrap within 20 seconds, so I don't think this
> > > > > > > > > is a good idea.
> > > > > > > > >
> > > > > > > > > The other proposal to calculate the error rate, rather than a fixed
> > > > > > > > > error boundary might be useful too, as if the current clocksource and
> > > > > > > > > watchdog are close, a long timer delay won't disqualify them if we
> > > > > > > > > scale the error bounds to be within an given error rate.
> > > > > > > >
> > > > > > > > In most of tsc unstable trouble shooting on modern servers we experienced,
> > > > > > > > it usually ends up in a false alarm triggered by the clock source
> > > > > > > > watchdog for tsc.
> > > > > > > >
> > > > > > > > I think Paul has a proposal to make a clock source watchdog to be more
> > > > > > > > intelligent.
> > > > > > > > Its job is to find a real problem instead of causing a problem.
> > > > > > >
> > > > > > > And that proposal is now in mainline:
> > > > > >
> > > > > > Great! : -)
> > > > > > >
> > > > > > > 22a223833716 clocksource: Print deviation in nanoseconds when a clocksource becomes unstable
> > > > > > > 1253b9b87e42 clocksource: Provide kernel module to test clocksource watchdog
> > > > > > > 2e27e793e280 clocksource: Reduce clocksource-skew threshold
> > > > > > > fa218f1cce6b clocksource: Limit number of CPUs checked for clock synchronization
> > > > > > > 7560c02bdffb clocksource: Check per-CPU clock synchronization when marked unstable
> > > > > > > db3a34e17433 clocksource: Retry clock read if long delays detected
> > > > > > >
> > > > > > > The strategy is to disqualify a clock comparison if the reads took too
> > > > > > > long, and to retry the comparison. If four consecutive comparison take
> > > > > > > too long, clock skew is reported. The number of consecutive comparisons
> > > > > > > may be adjusted by the usual kernel boot parameter.
> > > > > > >
> > > > > > > > so disabling it for known good-tsc might be a reasonable good idea
> > > > > > > > that can save manpower for other
> > > > > > > > more valuable problems to solve, or at least make it statistically a
> > > > > > > > problem less chance to happen.
> > > > > > >
> > > > > > > One additional piece that is still in prototype state in -rcu is to give
> > > > > > > clocksources some opportunity to resynchronize if there are too many
> > > > > > > slow comparisons. This is intended to handle cases where clocks often
> > > > > >
> > > > > > if there is such tsc-sync algorithm existing in software, it really
> > > > > > can help system software engineers
> > > > > > to solve some rare power good signals synchronization problem caused
> > > > > > by bios that caused
> > > > > > boot time tsc sync check failure that usually would consume huge
> > > > > > debugging engine for bringing up qualified linux system.
> > > > > >
> > > > > > Less depending on platform quirks should be good thing to linux for
> > > > > > tsc && rcu support.
> > > > >
> > > > > Good point, I have procrastinated long enough.
> > > > >
> > > > > How about like this?
> > > >
> > > > sorry, I meant a better algorithm to use tsc adjust register
> > > > like the tried one in arch/x86/kernel/tsc_sync.c
> > >
> > > Ah, at this time I must leave that sort of task to others.
> >
> > sure.
> > if anyone is still debugging clock-source watchdog issue, It is
> > highly appreciated and would be more helpful to others
> > that we truly need to decouple TSC with slow clock source.
> > we need to be aware of that when looking into clock source watchdog issues.
>
> There is a old saying that those with only one clock always know what
> time it is, but those with more than one clock never can be sure. ;-)

We do have many tsc clocks on these systems that can watch
each other. However, you are right that these tsc clocks are getting ticks
from the same base clock on the board.

We just need a better algorithm that can be better than the existing one.

And the value of it is it could finally terminate the fake alarms from
the current clock
source watchdog forever by introducing a next level of ns-diff complexities
where your code itself could be a high latency source that needs to be
eliminated . : -(

so , we need a genuine genius idea to make such code to surface from
lkml's brave hearts, otherwise
we will live with your clocksource watchdog code for quite a long time
in the foreseeable future.

Thanks again for your code. : -)
>
> In the testing and validation phases, one should supply a known good
> external clock against which to check everything. I could imagine doing
> something similar in production using any of a number of Internet time
> services, but that project is beyond what I can commit to any time soon.
> Note that it is not so simple because it must deal with arbitrary delays
> across the Internet, the possibility of broken Internet time services,
> and so on.
>
> But in the common case, I bet it would greatly simplify your debugging
> efforts!
>
> > And many thanks to the value of your patch, I 'm seeing another report
> > that obviously has carried "attempt 4, marking unstable"
> > one or two times at the beginning followed less occurrence after
> > hundreds of boot..
> > ： high priority --> medium
>
> I am glad that it helped!
>
> Thanx, Paul
>
> > > > > ------------------------------------------------------------------------
> > > > >
> > > > > commit 9ec2a03bbf4bee3d9fbc02a402dee36efafc5a2d
> > > > > Author: Paul E. McKenney <[email protected]>
> > > > > Date: Thu May 27 11:03:28 2021 -0700
> > > > >
> > > > > clocksource: Forgive repeated long-latency watchdog clocksource reads
> > > > >
> > > > > Currently, the clocksource watchdog reacts to repeated long-latency
> > > > > clocksource reads by marking that clocksource unstable on the theory that
> > > > > these long-latency reads are a sign of a serious problem. And this theory
> > > >
> > > > Maybe we need to use other core's tsc as a reference clock instead of
> > > > using HPET, which , to my knowledge , is the place where the problem happens.
> > > >
> > > > Ruling out HPET and other slow clock devices as the obvious wrong choice
> > > > of a reference clock for tsc, I guess there will be less chance we
> > > > (in kernel code)
> > > > will get bothered by other latency problems perceived in the clock
> > > > source watchdog.
> > >
> > > There have been a number of patches that identify systems that tend to
> > > have unreliable HPET implementations. Perhaps more systems are needed
> > > there, or maybe some of those patches need to be backported to the
> > > version of Linux that you are using.
> > >
> > > There was also a patch that identified systems that are expected to have
> > > reliable TSCs, and that de-emphasized HPET on such systems.
> > >
> > > Thanx, Paul
> > >
> > > > > does in fact have real-world support in the form of firmware issues [1].
> > > > >
> > > > > However, it is also possible to trigger this using stress-ng on what
> > > > > the stress-ng man page terms "poorly designed hardware" [2]. And it
> > > > > is not necessarily a bad thing for the kernel to diagnose cases where
> > > > > heavy memory-contention workloads are being run on hardware that is not
> > > > > designed for this sort of use.
> > > > >
> > > > > Nevertheless, it is quite possible that real-world use will result in
> > > > > some situation requiring that high-stress workloads run on hardware
> > > > > not designed to accommodate them, and also requiring that the kernel
> > > > > refrain from marking clocksources unstable.
> > > > >
> > > > > Therefore, react to persistent long-latency reads by leaving the
> > > > > clocksource alone, but using the old 62.5-millisecond skew-detection
> > > > > threshold. In addition, the offending clocksource is marked for
> > > > > re-initialization, which both restarts that clocksource with a clean bill
> > > > > of health and avoids false-positive skew reports on later watchdog checks.
> > > > > Once marked for re-initialization, the clocksource is not subjected to
> > > > > further watchdog checking until a subsequent successful read from that
> > > > > clocksource that is free of excessive delays.
> > > > >
> > > > > However, if clocksource.max_cswd_coarse_reads consecutive clocksource read
> > > > > attempts result in long latencies, a warning (splat) will be emitted.
> > > > > This kernel boot parameter defaults to 100, and this warning can be
> > > > > disabled by setting it to zero or to a negative value.
> > > > >
> > > > > [ paulmck: Apply feedback from Chao Gao ]
> > > > >
> > > > > Link: https://lore.kernel.org/lkml/20210513155515.GB23902@xsang-OptiPlex-9020/ # [1]
> > > > > Link: https://lore.kernel.org/lkml/20210521083322.GG25531@xsang-OptiPlex-9020/ # [2]
> > > > > Link: https://lore.kernel.org/lkml/20210521084405.GH25531@xsang-OptiPlex-9020/
> > > > > Link: https://lore.kernel.org/lkml/20210511233403.GA2896757@paulmck-ThinkPad-P17-Gen-1/
> > > > > Tested-by: Chao Gao <[email protected]>
> > > > > Signed-off-by: Paul E. McKenney <[email protected]>
> > > > >
> > > > > diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> > > > > index 316027c3aadc..61d2436ae9df 100644
> > > > > --- a/Documentation/admin-guide/kernel-parameters.txt
> > > > > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > > > > @@ -600,6 +600,14 @@
> > > > > loops can be debugged more effectively on production
> > > > > systems.
> > > > >
> > > > > + clocksource.max_cswd_coarse_reads= [KNL]
> > > > > + Number of consecutive clocksource_watchdog()
> > > > > + coarse reads (that is, clocksource reads that
> > > > > + were unduly delayed) that are permitted before
> > > > > + the kernel complains (gently). Set to a value
> > > > > + less than or equal to zero to suppress these
> > > > > + complaints.
> > > > > +
> > > > > clocksource.max_cswd_read_retries= [KNL]
> > > > > Number of clocksource_watchdog() retries due to
> > > > > external delays before the clock will be marked
> > > > > diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h
> > > > > index 1d42d4b17327..3e925d9ffc31 100644
> > > > > --- a/include/linux/clocksource.h
> > > > > +++ b/include/linux/clocksource.h
> > > > > @@ -110,6 +110,7 @@ struct clocksource {
> > > > > int rating;
> > > > > enum clocksource_ids id;
> > > > > enum vdso_clock_mode vdso_clock_mode;
> > > > > + unsigned int n_coarse_reads;
> > > > > unsigned long flags;
> > > > >
> > > > > int (*enable)(struct clocksource *cs);
> > > > > @@ -291,6 +292,7 @@ static inline void timer_probe(void) {}
> > > > > #define TIMER_ACPI_DECLARE(name, table_id, fn) \
> > > > > ACPI_DECLARE_PROBE_ENTRY(timer, name, table_id, 0, NULL, 0, fn)
> > > > >
> > > > > +extern int max_cswd_coarse_reads;
> > > > > extern ulong max_cswd_read_retries;
> > > > > void clocksource_verify_percpu(struct clocksource *cs);
> > > > >
> > > > > diff --git a/kernel/time/clocksource-wdtest.c b/kernel/time/clocksource-wdtest.c
> > > > > index df922f49d171..7e82500c400b 100644
> > > > > --- a/kernel/time/clocksource-wdtest.c
> > > > > +++ b/kernel/time/clocksource-wdtest.c
> > > > > @@ -145,13 +145,12 @@ static int wdtest_func(void *arg)
> > > > > else if (i <= max_cswd_read_retries)
> > > > > s = ", expect message";
> > > > > else
> > > > > - s = ", expect clock skew";
> > > > > + s = ", expect coarse-grained clock skew check and re-initialization";
> > > > > pr_info("--- Watchdog with %dx error injection, %lu retries%s.\n", i, max_cswd_read_retries, s);
> > > > > WRITE_ONCE(wdtest_ktime_read_ndelays, i);
> > > > > schedule_timeout_uninterruptible(2 * HZ);
> > > > > WARN_ON_ONCE(READ_ONCE(wdtest_ktime_read_ndelays));
> > > > > - WARN_ON_ONCE((i <= max_cswd_read_retries) !=
> > > > > - !(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE));
> > > > > + WARN_ON_ONCE(clocksource_wdtest_ktime.flags & CLOCK_SOURCE_UNSTABLE);
> > > > > wdtest_ktime_clocksource_reset();
> > > > > }
> > > > >
> > > > > diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> > > > > index b8a14d2fb5ba..796a127aabb9 100644
> > > > > --- a/kernel/time/clocksource.c
> > > > > +++ b/kernel/time/clocksource.c
> > > > > @@ -199,6 +199,9 @@ void clocksource_mark_unstable(struct clocksource *cs)
> > > > > spin_unlock_irqrestore(&watchdog_lock, flags);
> > > > > }
> > > > >
> > > > > +int max_cswd_coarse_reads = 100;
> > > > > +module_param(max_cswd_coarse_reads, int, 0644);
> > > > > +EXPORT_SYMBOL_GPL(max_cswd_coarse_reads);
> > > > > ulong max_cswd_read_retries = 3;
> > > > > module_param(max_cswd_read_retries, ulong, 0644);
> > > > > EXPORT_SYMBOL_GPL(max_cswd_read_retries);
> > > > > @@ -226,13 +229,22 @@ static bool cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
> > > > > pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
> > > > > smp_processor_id(), watchdog->name, nretries);
> > > > > }
> > > > > - return true;
> > > > > + cs->n_coarse_reads = 0;
> > > > > + return false;
> > > > > }
> > > > > + WARN_ONCE(max_cswd_coarse_reads > 0 &&
> > > > > + !(++cs->n_coarse_reads % max_cswd_coarse_reads),
> > > > > + "timekeeping watchdog on CPU%d: %s %u consecutive coarse-grained reads\n", smp_processor_id(), watchdog->name, cs->n_coarse_reads);
> > > > > }
> > > > >
> > > > > - pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, marking unstable\n",
> > > > > - smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > > > - return false;
> > > > > + if ((cs->flags & CLOCK_SOURCE_WATCHDOG) && !atomic_read(&watchdog_reset_pending)) {
> > > > > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, coarse-grained skew check followed by re-initialization\n",
> > > > > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > > > + } else {
> > > > > + pr_warn("timekeeping watchdog on CPU%d: %s read-back delay of %lldns, attempt %d, awaiting re-initialization\n",
> > > > > + smp_processor_id(), watchdog->name, wd_delay, nretries);
> > > > > + }
> > > > > + return true;
> > > > > }
> > > > >
> > > > > static u64 csnow_mid;
> > > > > @@ -356,6 +368,7 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > int next_cpu, reset_pending;
> > > > > int64_t wd_nsec, cs_nsec;
> > > > > struct clocksource *cs;
> > > > > + bool coarse;
> > > > > u32 md;
> > > > >
> > > > > spin_lock(&watchdog_lock);
> > > > > @@ -373,16 +386,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > continue;
> > > > > }
> > > > >
> > > > > - if (!cs_watchdog_read(cs, &csnow, &wdnow)) {
> > > > > - /* Clock readout unreliable, so give it up. */
> > > > > - __clocksource_unstable(cs);
> > > > > - continue;
> > > > > - }
> > > > > + coarse = cs_watchdog_read(cs, &csnow, &wdnow);
> > > > >
> > > > > /* Clocksource initialized ? */
> > > > > if (!(cs->flags & CLOCK_SOURCE_WATCHDOG) ||
> > > > > atomic_read(&watchdog_reset_pending)) {
> > > > > - cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > > > > + if (!coarse)
> > > > > + cs->flags |= CLOCK_SOURCE_WATCHDOG;
> > > > > cs->wd_last = wdnow;
> > > > > cs->cs_last = csnow;
> > > > > continue;
> > > > > @@ -403,7 +413,13 @@ static void clocksource_watchdog(struct timer_list *unused)
> > > > > continue;
> > > > >
> > > > > /* Check the deviation from the watchdog clocksource. */
> > > > > - md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > > > > + if (coarse) {
> > > > > + md = 62500 * NSEC_PER_USEC;
> > > > > + cs->flags &= ~CLOCK_SOURCE_WATCHDOG;
> > > > > + pr_warn("timekeeping watchdog on CPU%d: %s coarse-grained %lu.%03lu ms clock-skew check followed by re-initialization\n", smp_processor_id(), watchdog->name, md / NSEC_PER_MSEC, md % NSEC_PER_MSEC / NSEC_PER_USEC);
> > > > > + } else {
> > > > > + md = cs->uncertainty_margin + watchdog->uncertainty_margin;
> > > > > + }
> > > > > if (abs(cs_nsec - wd_nsec) > md) {
> > > > > pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as unstable because the skew is too large:\n",
> > > > > smp_processor_id(), cs->name);

2021-12-09 13:14:15

by Gang Li

[permalink] [raw]

Subject: Re: [PATCH] Clocksource: Avoid misjudgment of clocksource

Hi all,

How about changing clocksource_watchdog from classical timer to hrtimer?
hrtimer is more accurate and stable, and makes it much easier for us to
deal with misjudgments.

--
Thanks
Gang Li

2021-12-09 16:44:08