From nobody Mon Feb 9 06:29:01 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id C2888C46467 for ; Thu, 5 Jan 2023 01:07:11 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S230039AbjAEBHK (ORCPT ); Wed, 4 Jan 2023 20:07:10 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:44110 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229773AbjAEBHF (ORCPT ); Wed, 4 Jan 2023 20:07:05 -0500 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 1F8EB2F7B5 for ; Wed, 4 Jan 2023 17:07:04 -0800 (PST) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id A533A618A0 for ; Thu, 5 Jan 2023 01:07:03 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 06928C433D2; Thu, 5 Jan 2023 01:07:02 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1672880823; bh=AJeR1T6OoNxbdITdFAHVVUIQjCuiYAgVS5ruYDD+l3E=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=O1KAGj6RD8nDceB2/3J13gdWOW0YT7n2SIQMEb4PaMuUAM7LnhCfDq3js9BjHKySb Z7ykct1b8BpsoWmDMN2qkDIwX8zsr8wJ64WPQXUJ14Bz7G8IvKUjxG4RLRukCSBzv8 +/kzgQERoNL95VW4luKNjAvIPPLkeMKskJjvONzgvcehd2wPAG0mGUsoosTLb5KfUh TLCY7rNPV5EQOFxvSxJWhjeyLJLzfIy81E/CB3VvfGNTQL5oPZhVDWnGkEeCJ2CYs1 4uq6xtdNPEdNIazbr7T+uGCOUt+t+SbVSznSRCJ7HdQZ2zUDL1OG0LnmFW8Zryh9ME EOYPSWsm5zvPg== Received: by paulmck-ThinkPad-P17-Gen-1.home (Postfix, from userid 1000) id AE78E5C1456; Wed, 4 Jan 2023 17:07:02 -0800 (PST) From: "Paul E. McKenney" To: tglx@linutronix.de Cc: 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, feng.tang@intel.com, zhengjun.xing@intel.com, "Paul E. McKenney" , John Stultz Subject: [PATCH clocksource 4/6] clocksource: Improve "skew is too large" messages Date: Wed, 4 Jan 2023 17:06:59 -0800 Message-Id: <20230105010701.1773895-4-paulmck@kernel.org> X-Mailer: git-send-email 2.31.1.189.g2e36527f23 In-Reply-To: <20230105010429.GA1773522@paulmck-ThinkPad-P17-Gen-1> References: <20230105010429.GA1773522@paulmck-ThinkPad-P17-Gen-1> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" When clocksource_watchdog() detects excessive clocksource skew compared to the watchdog clocksource, it marks the clocksource under test as unstable and prints several lines worth of message. But that message is unclear to anyone unfamiliar with the code: clocksource: timekeeping watchdog on CPU2: Marking clocksource 'wdtest-ktim= e' as unstable because the skew is too large: clocksource: 'kvm-clock' wd_nsec: 400744390 wd_now: 6= 12625c2c wd_last: 5fa7f7c66 mask: ffffffffffffffff clocksource: 'wdtest-ktime' cs_nsec: 600744034 cs_now= : 173081397a292d4f cs_last: 17308139565a8ced mask: ffffffffffffffff clocksource: 'kvm-clock' (not 'wdtest-ktime') is curr= ent clocksource. Therefore, add the following line near the end of that message: Clocksource 'wdtest-ktime' skewed 199999644 ns (199 ms) over watchdog 'kvm-= clock' interval of 400744390 ns (400 ms) This new line clearly indicates the amount of skew between the two clocksources, along with the duration of the time interval over which the skew occurred, both in nanoseconds and milliseconds. Cc: John Stultz Cc: Thomas Gleixner Cc: Stephen Boyd Cc: Feng Tang Signed-off-by: Paul E. McKenney --- kernel/time/clocksource.c | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c index b59914953809f..fc486cd972635 100644 --- a/kernel/time/clocksource.c +++ b/kernel/time/clocksource.c @@ -446,12 +446,20 @@ static void clocksource_watchdog(struct timer_list *u= nused) /* Check the deviation from the watchdog clocksource. */ md =3D cs->uncertainty_margin + watchdog->uncertainty_margin; if (abs(cs_nsec - wd_nsec) > md) { + u64 cs_wd_msec; + u64 wd_msec; + u32 wd_rem; + pr_warn("timekeeping watchdog on CPU%d: Marking clocksource '%s' as uns= table because the skew is too large:\n", smp_processor_id(), cs->name); pr_warn(" '%s' wd_nsec: %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); + cs_wd_msec =3D div_u64_rem(cs_nsec - wd_nsec, 1000U * 1000U, &wd_rem); + wd_msec =3D div_u64_rem(wd_nsec, 1000U * 1000U, &wd_rem); + pr_warn(" Clocksource '%s' skewed %lld ns (%lld ms= ) over watchdog '%s' interval of %lld ns (%lld ms)\n", + cs->name, cs_nsec - wd_nsec, cs_wd_msec, watchdog->name, wd_nsec, wd_m= sec); if (curr_clocksource =3D=3D cs) pr_warn(" '%s' is current clocksource.\n", cs->na= me); else if (curr_clocksource) --=20 2.31.1.189.g2e36527f23