Messages in this thread | | | Date | Sun, 29 May 2022 17:16:59 -0500 | Subject | Re: [PATCH] clocksource: Make clocksource watchdog check with WATCHDOG_INTERVAL period | From | Michael Larabel <> |
| |
On 5/27/22 21:07, Waiman Long wrote: > On 5/27/22 21:57, Waiman Long wrote: >> Since commit c86ff8c55b8a ("clocksource: Avoid accidental unstable >> marking of clocksource"), a new WD_READ_SKIP value was introduced >> as a possible return value of cs_watchdog_read() to skip the current >> check. However, this has an undesriable side effect of extending the >> time gap between csnow and cs_last to more than one WATCHDOG_INTERVAL >> (0.5s) in case of intermittent WD_READ_SKIP's. >> >> There was an instance of reported clocksource watchdog failure with >> the time skew of 485us where the uncertainly threshold is 400us. In >> that particular case, the (now - last) gap was about 2s. Looking at >> the dmesg log, it was clear there was a successful cs_watchdog_read() >> followed by 3 skips and then another successful cs_watchdog_read(). >> >> If there is an existing skew between the hpet (watchdog) and tsc >> clocksource, enlarging the period by 4x will certainly increase the >> measured skew causing it to exceed the threshold in this case. Fix >> this variable period problem by resetting the CLOCK_SOURCE_WATCHDOG bit >> after each WD_READ_SKIP to force the reloading of wd_last and cs_last >> in the next round. This ensures that we have two consecutive successful >> cs_watchdog_read()'s before checking the clock skew. >> >> Fixes: c86ff8c55b8a ("clocksource: Avoid accidental unstable marking >> of clocksource") >> Reported-by: Michael Larabel <Michael@phoronix.com> >> Signed-off-by: Waiman Long <longman@redhat.com> >> --- >> kernel/time/clocksource.c | 11 ++++++++++- >> 1 file changed, 10 insertions(+), 1 deletion(-) >> >> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c >> index cee5da1e54c4..173e052c12b6 100644 >> --- a/kernel/time/clocksource.c >> +++ b/kernel/time/clocksource.c >> @@ -411,9 +411,18 @@ static void clocksource_watchdog(struct >> timer_list *unused) >> read_ret = cs_watchdog_read(cs, &csnow, &wdnow); >> if (read_ret != WD_READ_SUCCESS) { >> - if (read_ret == WD_READ_UNSTABLE) >> + if (read_ret == WD_READ_UNSTABLE) { >> /* Clock readout unreliable, so give it up. */ >> __clocksource_unstable(cs); >> + } else { /* WD_READ_SKIP */ >> + /* >> + * Watchdog clock unstable at the moment, >> + * discard the stored wd_last and cs_last to >> + * make sure the gap between now and last >> + * is always one WATCHDOG_INTERVAL. >> + */ >> + cs->flags &= ~CLOCK_SOURCE_WATCHDOG; >> + } >> continue; >> } > > Sorry, I accidentally use the old email address for John. > > Cheers, > Longman
I've tested this patch on the affected Daytona + Milan-X system and can confirm it does fix the performance problem that led to this issue. Though it is spamming the kernel log now every half-second with clocksource messages, not sure if that is intended/desirable behavior?
[ 0.000000] tsc: Fast TSC calibration using PIT [ 0.000000] tsc: Detected 2195.990 MHz processor [ 1.238759] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1fa766bc6ba, max_idle_ns: 440795275714 ns [ 2.769608] clocksource: Switched to clocksource tsc-early [ 3.263925] clocksource: wd-tsc-early-wd read-back delay of 292215ns, clock-skew test skipped! [ 3.743804] clocksource: wd-tsc-early-wd read-back delay of 268469ns, clock-skew test skipped! [ 3.935663] tsc: Refined TSC clocksource calibration: 2195.274 MHz [ 3.935844] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1fa4c255513, max_idle_ns: 440795289702 ns [ 3.936449] clocksource: Switched to clocksource tsc [ 4.255932] clocksource: wd-tsc-wd read-back delay of 260228ns, clock-skew test skipped! [ 4.767892] clocksource: wd-tsc-wd read-back delay of 272520ns, clock-skew test skipped! [ 5.247581] clocksource: wd-tsc-wd read-back delay of 200444ns, clock-skew test skipped! [ 5.759560] clocksource: wd-tsc-wd read-back delay of 165942ns, clock-skew test skipped! [ 6.239687] clocksource: wd-tsc-wd read-back delay of 232222ns, clock-skew test skipped! [ 7.264014] clocksource: wd-tsc-wd read-back delay of 282927ns, clock-skew test skipped! [ 7.743864] clocksource: wd-tsc-wd read-back delay of 288374ns, clock-skew test skipped! [ 8.255590] clocksource: wd-tsc-wd read-back delay of 206730ns, clock-skew test skipped! [ 8.767778] clocksource: wd-tsc-wd read-back delay of 267771ns, clock-skew test skipped! [ 9.247870] clocksource: wd-tsc-wd read-back delay of 224469ns, clock-skew test skipped! [ 10.239340] clocksource: wd-tsc-wd read-back delay of 109720ns, clock-skew test skipped! [ 12.255276] clocksource: wd-tsc-wd read-back delay of 104692ns, clock-skew test skipped! [ 16.255362] clocksource: wd-tsc-wd read-back delay of 122780ns, clock-skew test skipped! [ 17.759335] clocksource: wd-tsc-wd read-back delay of 155885ns, clock-skew test skipped! [ 18.239500] clocksource: wd-tsc-wd read-back delay of 176558ns, clock-skew test skipped! [ 18.751341] clocksource: wd-tsc-wd read-back delay of 157352ns, clock-skew test skipped! [ 19.263618] clocksource: wd-tsc-wd read-back delay of 177606ns, clock-skew test skipped! [ 19.743487] clocksource: wd-tsc-wd read-back delay of 157841ns, clock-skew test skipped! [ 20.255482] clocksource: wd-tsc-wd read-back delay of 157701ns, clock-skew test skipped! [ 20.767634] clocksource: wd-tsc-wd read-back delay of 173136ns, clock-skew test skipped! [ 21.247405] clocksource: wd-tsc-wd read-back delay of 175441ns, clock-skew test skipped! ...
Thanks, Michael
| |