Re: [PATCH v10 clocksource 6/7] clocksource: Forgive tsc_early pre-calibration drift

["Paul E. McKenney" <paulmck@kernel.org>]

On Tue, Apr 27, 2021 at 09:13:55AM +0800, Feng Tang wrote:
> On Mon, Apr 26, 2021 at 11:26:52AM -0700, Paul E. McKenney wrote:
> > On Mon, Apr 26, 2021 at 11:36:05PM +0800, Feng Tang wrote:
> > > On Mon, Apr 26, 2021 at 08:25:29AM -0700, Paul E. McKenney wrote:
> > > > On Mon, Apr 26, 2021 at 11:01:27PM +0800, Feng Tang wrote:
> > > > > Hi Paul,
> > > > > 
> > > > > On Sun, Apr 25, 2021 at 03:47:07PM -0700, Paul E. McKenney wrote:
> > > > > > Because the x86 tsc_early clocksource is given a quick and semi-accurate
> > > > > > calibration (by design!), it might have drift rates well in excess of
> > > > > > the 0.1% limit that is in the process of being adopted.
> > > > > > 
> > > > > > Therefore, add a max_drift field to the clocksource structure that, when
> > > > > > non-zero, specifies the maximum allowable drift rate in nanoseconds over
> > > > > > a half-second period.  The tsc_early clocksource initializes this to five
> > > > > > miliseconds, which corresponds to the 1% drift rate limit suggested by
> > > > > > Xing Zhengjun.  This max_drift field is intended only for early boot,
> > > > > > so clocksource_watchdog() splats if it encounters a non-zero value in
> > > > > > this field more than 60 seconds after boot, inspired by a suggestion by
> > > > > > Thomas Gleixner.
> > > > > > 
> > > > > > This was tested by setting the clocksource_tsc ->max_drift field to 1,
> > > > > > which, as expected, resulted in a clock-skew event.
> > > > > 
> > > > > We've run the same last for this v10, and those 'unstable' thing [1] can
> > > > > not be reproduced!
> > > > 
> > > > Good to hear!  ;-)
> > > > 
> > > > > We've reported one case that tsc can be wrongly judged as 'unstable'
> > > > > by 'refined-jiffies' watchdog [1], while reducing the threshold could
> > > > > make it easier to be triggered.
> > > > > 
> > > > > It could be reproduced on the a plaform with a 115200 serial console,
> > > > > and hpet been disabled (several x86 platforms has this), add 
> > > > > 'initcall_debug' cmdline parameter to get more debug message, we can
> > > > > see:
> > > > > 
> > > > > [    1.134197] clocksource: timekeeping watchdog on CPU1: Marking clocksource 'tsc-early' as unstable because the skew is too large:
> > > > > [    1.134214] clocksource:                       'refined-jiffies' wd_nesc: 500000000 wd_now: ffff8b35 wd_last: ffff8b03 mask: ffffffff
> > > > > [    1.134217] clocksource:                       'tsc-early' cs_nsec: 507537855 cs_now: 4e63c9d09 cs_last: 4bebd81f5 mask: ffffffffffffffff
> > > > > [    1.134220] clocksource:                       No current clocksource.
> > > > > [    1.134222] tsc: Marking TSC unstable due to clocksource watchdog
> > > > 
> > > > Just to make sure I understand: "could be reproduced" as in this is the
> > > > result from v9, and v10 avoids this, correct?
> > > 
> > > Sorry I didn't make it clear. This is a rarely happened case, and can
> > > be reproduced with upstream kerenl, which has 62.5 ms threshold. 6/7 &
> > > 7/7 patch of reducing the threshold can make it easier to be triggered.
> > 
> > Ah, OK, so this could be considered to be a benefit of this series, then.
> > 
> > Does this happen only for tsc-early, or for tsc as well?
> > 
> > Has it already been triggered on v10 of this series?  (I understand that
> > it certainly should be easier to trigger, just curious whether this has
> > already happened.)
> 
> Yes, it has. The upper log is from v10 (actually it's the 'dev' branch
> of your linux-rcu git, which I didn't find obvious difference) on a
> client platform 
> 
>  [    1.134214] clocksource:    'refined-jiffies' wd_nesc: 500000000 wd_now: ffff8b35 wd_last: ffff8b03 mask: ffffffff
>  [    1.134217] clocksource:    'tsc-early' cs_nsec: 507537855 cs_now: 4e63c9d09 cs_last: 4bebd81f5 mask: ffffffffffffffff
> 
> The deviation is 7537855 ns (7.5 ms). And as said before, it needs many
> pre-conditions to be triggered.
> 
> Also I found the debug patch is useful, which prints out the direct
> nanoseconds info when 'unstable' is detected.

Looks good to me!

If you give me a Signed-off-by, I would be happy to queue it.

							Thanx, Paul

> kernel/time/clocksource.c | 8 ++++----
>  1 file changed, 4 insertions(+), 4 deletions(-)
> 
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index a374cf7b6336..5370f0c84981 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -443,10 +443,10 @@ static void clocksource_watchdog(struct timer_list *unused)
>  		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);
> -			pr_warn("                      '%s' wd_now: %llx wd_last: %llx mask: %llx\n",
> -				watchdog->name, wdnow, wdlast, watchdog->mask);
> -			pr_warn("                      '%s' cs_now: %llx cs_last: %llx mask: %llx\n",
> -				cs->name, csnow, cslast, cs->mask);
> +			pr_warn("                      '%s' wd_nesc: %lld wd_now: %llx wd_last: %llx mask: %llx\n",
> +				watchdog->name, wd_nsec, wdnow, wdlast, watchdog->mask);
> +			pr_warn("                      '%s' cs_nsec: %lld cs_now: %llx cs_last: %llx mask: %llx\n",
> +				cs->name, cs_nsec, csnow, cslast, cs->mask);
>  			if (curr_clocksource == cs)
>  				pr_warn("                      '%s' is current clocksource.\n", cs->name);
>  			else if (curr_clocksource)
> -- 
> 2.27.0
> 
> Thanks,
> Feng
> 
> 
> 
> > 
> > 							Thanx, Paul