Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Date:   Wed, 30 Nov 2022 12:49:24 +0800
From:   Feng Tang <feng.tang@intel.com>
To:     "Paul E. McKenney" <paulmck@kernel.org>
CC:     Thomas Gleixner <tglx@linutronix.de>,
        <linux-kernel@vger.kernel.org>, <john.stultz@linaro.org>,
        <sboyd@kernel.org>, <corbet@lwn.net>, <Mark.Rutland@arm.com>,
        <maz@kernel.org>, <kernel-team@meta.com>, <neeraju@codeaurora.org>,
        <ak@linux.intel.com>, <zhengjun.xing@intel.com>,
        Chris Mason <clm@meta.com>, John Stultz <jstultz@google.com>,
        Waiman Long <longman@redhat.com>
Subject: Re: [PATCH clocksource 1/3] clocksource: Reject bogus watchdog
 clocksource measurements
Message-ID: <Y4bg1H/HLRLfucNO@feng-clx>
References: <Y3rMc2VbgVLHN9db@feng-clx>
 <20221121181449.GA3774542@paulmck-ThinkPad-P17-Gen-1>
 <Y3zxB6r1kin8pSH1@feng-clx>
 <20221122220712.GP4001@paulmck-ThinkPad-P17-Gen-1>
 <Y32HFE+BaATh9+l/@feng-clx>
 <20221123212348.GI4001@paulmck-ThinkPad-P17-Gen-1>
 <Y4QZzzk+FdGj4AXm@feng-clx>
 <20221129192915.GD4001@paulmck-ThinkPad-P17-Gen-1>
 <Y4az+FT5YjpAWjZc@feng-clx>
 <20221130041206.GK4001@paulmck-ThinkPad-P17-Gen-1>
Content-Type: text/plain; charset="utf-8"
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: <20221130041206.GK4001@paulmck-ThinkPad-P17-Gen-1>
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0: =?utf-8?B?VzdPUlQ0cXAyNHhheXhBL3duWWcvYzliVVViWm55TDdQM2pHdmdLUEVYUEJh?=
 =?utf-8?B?blpxQXEwTGIyTFFlMzM1QVhMRDZLeVBONVJrNmxIZ215WWNNYXN4eTFSSUg2?=
 =?utf-8?B?QjBjMVU3VWFLQ3NQdklHK0FnL2VJMnV1TG5lcElkbkZIeXMyNFovZjNNM0Nq?=
 =?utf-8?B?QmtIcWdVbmhPakxRYk9aSHRHTk85TjlyVC9XcDd4NURlbUFQY2dhcDZXSTFW?=
 =?utf-8?B?WkpMRHFMdjNkbWpHVlVLNnFpZjZTY3JWWXVZS3U2ZGFKdmF6ek9oc0h1RGhk?=
 =?utf-8?B?R09jeHNiRXdodkJEUCtscDBYREVFT1RTT3N6OFZZYi9nSitLY2YyUkdUTS9U?=
 =?utf-8?B?YW9zRGc3UjFPdk4xQ2VvMmlkRlpxekhxaVJLUzdpQmVwalZsdEZ4YjNLcU96?=
 =?utf-8?B?WkZKZnk5cVVnL3FsY0N3a2d2RTlTTi9UOXMrM3p0ZXg4cStSTWdqdlpOU2ZS?=
 =?utf-8?B?a1F4cWpJSlh5VnFqZXB1bFNmWDRaT1NvcGVBTzFQd0lDcFpZUjJWUmVCdmVE?=
 =?utf-8?B?UjZmN0FZWFVMYXJOaVV5MTJQMURSbzJ6ditkek1tYm82WHRzOW1nd2pDN0VC?=
 =?utf-8?B?ZFdaQktkUEhmZUtzUnQ0YUJ4NTFsNG9NczJJU2hMTUxmVHhyeHBzQU9MODZO?=
 =?utf-8?B?N3dHS0Q0aXRUUDFFdm5wVUlDZ2k2SnpYRk5KbEdZL2k4SzRwWDZEa1RRNmV6?=
 =?utf-8?B?QWgzVFN6LzQ0VTNPdnhXSnd0alVsVFY3S091Y3M3amZnb3JDTkNzYVMwa3hJ?=
 =?utf-8?B?OUg2b0Eybys5WXJMODJIQ1o5NHgwWEludmU1UDRJcWswa0U5N3M2QS9hcG9U?=
 =?utf-8?B?Z1ZuU0pOMy9qWXljckc1MmlZOTNDZFQrbFg5VWJtTnJDVHBuN2F2cUw3RElW?=
 =?utf-8?B?VzVRVDVGbG1xM2o5ZHJWekFZYWJkTG1rYVQyZlhsZVo0Q0E5eE1OQ0VkRThF?=
 =?utf-8?B?bWtDckZLcFg1aU5FWlNldVpDTThTcnhESlptMGlZeml1QjZ6bmZNVHpWZlNW?=
 =?utf-8?B?TUlLZEVWWDcwUi9kc0I1VGxBTEhqYXlucmQvTFE4T1dBb0lja2ttTDk0OHZk?=
 =?utf-8?B?VXhnRC9WckZEYndMdVpFdXVnNjlueVpHbXVoVzEwSC9vWEpJMFFkeVJVS3R5?=
 =?utf-8?B?aVQ3S2l3cjBsNDNldHR6d3NoZVBDMUg5c2tnUEtJbzVHK0pzYVA3M2E1UDIz?=
 =?utf-8?B?VVZ3cHc4V2tuV2dIaWI1cWxZNmZOU2FWRnM5OUgvS3JzRFRkZnBEamUyaDFD?=
 =?utf-8?B?Q1ZBWnlUTmNIaGNXdndsZXZRTVQxWDd4SUV4VjI5TEU5SDZQWmFGNWkzWGMw?=
 =?utf-8?B?YXp5SVJNYWMxUlVQdnR6a2FLbW9jUmhSNU45ZUY2TFB3Q1JYK3NxWTFqSzFq?=
 =?utf-8?B?RkZUZW1zYWNRVVZuV3M3alNxNExrUS8vN3lRL3FXYXlCeGxnaDJ6V2FMVFBB?=
 =?utf-8?B?T0NlMHhzOXBZUExoRkQ1NGZlNllWQndlWloyRjNUTlFoRC9saUROZlhQakNz?=
 =?utf-8?B?eDVFMWJ6MnBmaW5qanp2RFBMRk1RaDgxUzRNbEJkUjVzOG02MjJQbU5pazlC?=
 =?utf-8?B?aFN2N1UyY0w3bHVEQU5PdXo1WVkvdWd4bGVtdERkRk5zeFhBQjZkNitMdkJD?=
 =?utf-8?B?a3MxVmpILzdIN0hLQkVLbThUMFo4MXkzMnA5Rjd6M0F6SklHajVCazQwMWZi?=
 =?utf-8?B?bVczVVp6ck1kZlZoUnBaTGdLY1RhWUVtUDB3WS8xbGZDbytkQWxhcGh5RXZT?=
 =?utf-8?B?SmJpaEltZ2Zkb1IvRzRjMjJEU01GU0FKaFdmdU02MDc3NE9LL2RzMEdNUS9q?=
 =?utf-8?B?N200Y0xkWVFqckhtUWRYemd3dTY1RSs5VVNReDNsVnhKa3RZWjkwc3FTRi8x?=
 =?utf-8?B?Ym1nWkVZc09MbVdkRGpaaVFVUHVJbkFlRFU4TEZ0Z1hncHcrT3hmRUUwYTB6?=
 =?utf-8?B?cDc0RG4rRzU2d1U5cU9KYTR6WWV3cnRJY3Y1V2NOelRoMmxxTldpZUVYQ1lE?=
 =?utf-8?B?MmJ3UkoyUlA2cUxJNmtDZktVY1Y5K1BvbW00QWpwQS9ibWg2d0JhcDZUWGFT?=
 =?utf-8?B?MVpjeTRCOEk0V2cxenc1YlJZc2k0azhKRHBuZU02Skl4UTdBS290T0ZPdXlM?=
 =?utf-8?Q?9BrynK5C9Rcv5tIuFrnnA1kQR?=
X-MS-Exchange-CrossTenant-Network-Message-Id: e1614405-e969-4b07-646c-08dad28eafba
X-MS-Exchange-CrossTenant-AuthSource: MN0PR11MB6304.namprd11.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 30 Nov 2022 04:52:31.4573
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 46c98d88-e344-4ed4-8496-4ed7712e255d
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: tJrqEeXMxZk5dNFUWZCtErSbcM2pcS6DnBp8bRqga6aMa0vldxUmUnmuysZVU/zfTViCUL8bvEn1NbnUo6j5Rg==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: IA1PR11MB6121
X-OriginatorOrg: intel.com
X-Spam-Status: No, score=-4.4 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH,
        DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,RCVD_IN_DNSWL_MED,
        SPF_HELO_NONE,SPF_NONE autolearn=ham autolearn_force=no version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on
        lindbergh.monkeyblade.net
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

On Tue, Nov 29, 2022 at 08:12:06PM -0800, Paul E. McKenney wrote:
> On Wed, Nov 30, 2022 at 09:38:00AM +0800, Feng Tang wrote:
> > On Tue, Nov 29, 2022 at 11:29:15AM -0800, Paul E. McKenney wrote:
> > [...]
> > > > > > IIUC, this will make TSC to watchdog HPET every 500 ms. We have got
> > > > > > report that the 500ms watchdog timer had big impact on some parallel
> > > > > > workload on big servers, that was another factor for us to seek
> > > > > > stopping the timer.
> > > > > 
> > > > > Another approach would be to slow it down.  Given the tighter bounds
> > > > > on skew, it could be done every (say) 10 seconds while allowing
> > > > > 2 milliseconds skew instead of the current 100 microseconds.
> > > > 
> > > > Yes, this can reduce the OS noise much. One problem is if we make it
> > > > a general interface, there is some clocksource whose warp time is
> > > > less than 10 seconds, like ACPI PM_TIMER (3-4 seconds), and I don't
> > > > know if other ARCHs have similar cases.
> > > 
> > > Maybe a simpler approach is for systems with such high sensitivity to
> > > OS noise to simply disable the clocksource watchdog.  ;-)
> > 
> > That's what the reported did, test with and without "tsc=reliable"
> > parameter :)
> > 
> > And AFAIK, many customers with big server farms hate to add more
> > cmdline parameters when we suggested so.
> 
> It can be surprisingly hard.  It is sometimes easier to patch the kernel
> to change the default. 

Indeed, sometimes we were askd to provide patch than cmdline parameters :)

> Part of the problem is getting the right set
> of command-line parameters associated with the right versions of the
> kernel in the not-uncommon case where different portions of the server
> farm are running different versions of the kernel.
> 
> > > > > > Is this about the concern of possible TSC frequency calibration
> > > > > > issue, as the 40 ms per second drift between HPET and TSC? With 
> > > > > > b50db7095fe0 backported, we also have another patch to force TSC
> > > > > > calibration for those platforms which get the TSC freq directly
> > > > > > from CPUID or MSR and don't have such info in dmesg:
> > > > > >  "tsc: Refined TSC clocksource calibration: 2693.509 MHz" 
> > > > > > 
> > > > > > https://lore.kernel.org/lkml/20220509144110.9242-1-feng.tang@intel.com/
> > > > > > 
> > > > > > We did met tsc calibration issue due to some firmware issue, and
> > > > > > this can help to catch it. You can try it if you think it's relevant.
> > > > > 
> > > > > I am giving this a go, thank you!
> > > > 
> > > > Thanks for spending time testing it!
> > > 
> > > And here are the results from setting tsc_force_recalibrate to 1:
> > > 
> > > $ dmesg | grep -E 'calibrat|clocksource'
> > > [    5.272939] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
> > > [   16.830644] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
> > > [   17.938020] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x36a8d32ce31, max_idle_ns: 881590731004 ns
> > > [   24.548583] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
> > > [   49.762432] clocksource: Switched to clocksource tsc-early
> > > [   50.076769] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
> > > [   55.615946] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x36a8d32ce31, max_idle_ns: 881590731004 ns
> > > [   55.640270] clocksource: Switched to clocksource tsc
> > > [   56.694371] tsc: Warning: TSC freq calibrated by CPUID/MSR differs from what is calibrated by HW timer, please check with vendor!!
> > > [   56.724550] tsc: Previous calibrated TSC freq:        1896.000 MHz
> > > [   56.737646] tsc: TSC freq recalibrated by [HPET]:     1975.000 MHz
> > 
> > Looks like there is really something wrong here. I assume the first
> > number '1896 MHz' is got from CPUID(0x15)'s math calculation.
> 
> How about this from earlier in that same console?
> 
> [    0.000000] efi: EFI v2.80 by American Megatrends
> [    0.000000] efi: ACPI=0x6f569000 ACPI 2.0=0x6f569014 TPMFinalLog=0x6f56b000 SMBIOS=0x753e1000 SMBIOS 3.0=0x753e0000 MEMATTR=0x62176018 ESRT=0x64bd1018 TPMEventLog=0x58737018
> [    0.000000] [Firmware Bug]: TPM Final Events table missing or invalid
> [    0.000000] SMBIOS 3.5.0 present.
> [    0.000000] DMI: Quanta Grand Teton 1F0TUBZ0007/Grand Teton MB, BIOS F0T_1A15 08/25/2022
> [    0.000000] tsc: Detected 1900.000 MHz processor
> [    0.000000] tsc: Detected 1896.000 MHz TSC

I'm still not sure, but it's likely from CPUID(0x15). I met cases
that even severs of same generations get their tsc frequence from
different sources.

I locally have debug patch to check it:

diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index cafacb2e58cc..82ddb4b0529a 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -654,8 +654,11 @@ unsigned long native_calibrate_tsc(void)
 	 * frequency and is the most accurate one so far we have. This
 	 * is considered a known frequency.
 	 */
-	if (crystal_khz != 0)
+	if (crystal_khz != 0) {
+		printk("tsc: using CPUID[0x15] crystal_khz= %d kHz ebx=%d eax=%d\n",
+		crystal_khz, ebx_numerator, eax_denominator);
 		setup_force_cpu_cap(X86_FEATURE_TSC_KNOWN_FREQ);
+	}
 
 	/*
 	 * Some Intel SoCs like Skylake and Kabylake don't report the crystal
@@ -668,6 +671,7 @@ unsigned long native_calibrate_tsc(void)
 		cpuid(0x16, &eax_base_mhz, &ebx, &ecx, &edx);
 		crystal_khz = eax_base_mhz * 1000 *
 			eax_denominator / ebx_numerator;
+		printk("tsc: using CPUID[0x16] base_khz=%d kHz\n", crystal_khz);
 	}
 
 	if (crystal_khz == 0)

This remind me that maybe we can add a line in dmesg telling people
which exact soure that the TSC frequency comes from (CPUID, MSR or
calibration from HW timers like HPET/PM_TIMER).

> > I thinks 2 more things could be try:
> > 
> > * add "nohpet" to the cmdline, so the tsc_force_recalibrate should use
> >   ACPI PM_TIMER to do the calibration, say a third-party check.
> 
> OK, getting things teed up for TSC recalibration and nohpet.
> 
> > * If the system don't have auto-adjusted time setting like NTP, I
> >   guess the system time will have obvious drift comparing to a normal
> >   clock or a mobile phone time, as the deviation is about 4%, which
> >   is 2.4 minutes per hour.
> 
> No ntpd, but there is a chronyd.
> 
> I will let you know what happens with HPET disabled and TSC recalibration
> enabled.

Thanks!

- Feng

> 							Thanx, Paul