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;
From:   "Maciej S. Szmigiero" <mail@maciej.szmigiero.name>
To:     John Stultz <jstultz@google.com>,
        Thomas Gleixner <tglx@linutronix.de>,
        Stephen Boyd <sboyd@kernel.org>
Cc:     linux-kernel@vger.kernel.org
Subject: [PATCH] clocksource: downgrade messages about skipping watchdog check under load
Date:   Mon, 29 Aug 2022 21:11:38 +0200
Message-Id: <841757364754f8d0a8834982ca16da10a6a44d72.1661799955.git.maciej.szmigiero@oracle.com>
MIME-Version: 1.0
Content-Transfer-Encoding: 8bit
Precedence: bulk

From: "Maciej S. Szmigiero" <maciej.szmigiero@oracle.com>

Since commit c86ff8c55b8a ("clocksource: Avoid accidental unstable marking of clocksources")
the watchdog check is skipped if two consecutive watchdog reads are too far
apart.

This might happen, for example, when the system is under heavy load, so it
isn't a totally unexpected condition.

Since some systems are prone to producing significant number of these
messages when the system is constantly under heavy load downgrade their log
level to "debug" to avoid filling the kernel log in such case.

These messages can then still be enabled via dyndbg mechanism in case
someone really needs to see them.

Signed-off-by: Maciej S. Szmigiero <maciej.szmigiero@oracle.com>
---
 kernel/time/clocksource.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
index cee5da1e54c41..ff99b25bc1aec 100644
--- a/kernel/time/clocksource.c
+++ b/kernel/time/clocksource.c
@@ -236,8 +236,8 @@ static enum wd_read_status cs_watchdog_read(struct clocksource *cs, u64 *csnow,
 					      watchdog->shift);
 		if (wd_delay <= WATCHDOG_MAX_SKEW) {
 			if (nretries > 1 || nretries >= max_cswd_read_retries) {
-				pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
-					smp_processor_id(), watchdog->name, nretries);
+				pr_debug("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
+					 smp_processor_id(), watchdog->name, nretries);
 			}
 			return WD_READ_SUCCESS;
 		}
@@ -262,10 +262,10 @@ static enum wd_read_status cs_watchdog_read(struct clocksource *cs, u64 *csnow,
 	return WD_READ_UNSTABLE;
 
 skip_test:
-	pr_info("timekeeping watchdog on CPU%d: %s wd-wd read-back delay of %lldns\n",
-		smp_processor_id(), watchdog->name, wd_seq_delay);
-	pr_info("wd-%s-wd read-back delay of %lldns, clock-skew test skipped!\n",
-		cs->name, wd_delay);
+	pr_debug("timekeeping watchdog on CPU%d: %s wd-wd read-back delay of %lldns\n",
+		 smp_processor_id(), watchdog->name, wd_seq_delay);
+	pr_debug("wd-%s-wd read-back delay of %lldns, clock-skew test skipped!\n",
+		 cs->name, wd_delay);
 	return WD_READ_SKIP;
 }