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:   Costa Shulyupin <costa.shul@redhat.com>
To:     Thomas Gleixner <tglx@linutronix.de>,
        Costa Shulyupin <costa.shul@redhat.com>,
        "Paul E. McKenney" <paulmck@kernel.org>,
        linux-kernel@vger.kernel.org (open list)
Cc:     junxiao.chang@intel.com, pauld@redhat.com, prarit@redhat.com
Subject: [RFC PATCH] hrtimer: warn when delay is too long
Date:   Sun, 23 Jul 2023 21:31:30 +0300
Message-ID: <20230723183132.1910579-1-costa.shul@redhat.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=true
Content-Transfer-Encoding: 8bit
Precedence: bulk

Checking hrtimer_get_softexpires value because sometimes it is 1,
at least for 4.18.0-372.49.1.rt7.206.el8_6.

This patch helped debug a very big problem and find this solution:
https://lore.kernel.org/lkml/20221208075604.811710-1-junxiao.chang@intel.com/

Signed-off-by: Costa Shulyupin <costa.shul@redhat.com>
---
 kernel/time/Kconfig   |  6 ++++++
 kernel/time/hrtimer.c | 14 ++++++++++++++
 2 files changed, 20 insertions(+)

diff --git a/kernel/time/Kconfig b/kernel/time/Kconfig
index bae8f11070be..ccc1458b2ba6 100644
--- a/kernel/time/Kconfig
+++ b/kernel/time/Kconfig
@@ -196,6 +196,12 @@ config HIGH_RES_TIMERS
 	  hardware is not capable then this option only increases
 	  the size of the kernel image.
 
+config HIGH_RES_TIMERS_DEBUG
+	bool "High Resolution Timer Debug"
+	default y if HIGH_RES_TIMERS && DEBUG_KERNEL
+	help
+	  Warn when hrtimer delay is too long.
+
 config CLOCKSOURCE_WATCHDOG_MAX_SKEW_US
 	int "Clocksource watchdog maximum allowable skew (in μs)"
 	depends on CLOCKSOURCE_WATCHDOG
diff --git a/kernel/time/hrtimer.c b/kernel/time/hrtimer.c
index 238262e4aba7..d0087b709bc1 100644
--- a/kernel/time/hrtimer.c
+++ b/kernel/time/hrtimer.c
@@ -123,6 +123,10 @@ static const int hrtimer_clock_to_base_table[MAX_CLOCKS] = {
 	[CLOCK_TAI]		= HRTIMER_BASE_TAI,
 };
 
+#ifdef CONFIG_HIGH_RES_TIMERS_DEBUG
+int timer_threshold_ns = 1000000;
+#endif
+
 /*
  * Functions and macros which are different for UP/SMP systems are kept in a
  * single place
@@ -1651,6 +1655,16 @@ static void __run_hrtimer(struct hrtimer_cpu_base *cpu_base,
 	bool expires_in_hardirq;
 	int restart;
 
+#ifdef CONFIG_HIGH_RES_TIMERS_DEBUG
+	if (timer_threshold_ns && hrtimer_get_softexpires(timer) > 0) {
+		s64 delay_ns = ktime_to_ns(ktime_sub(*now,
+					   hrtimer_get_softexpires(timer)));
+
+		if (delay_ns > timer_threshold_ns)
+			printk_deferred(KERN_WARNING
+					"hrtimer: delay_ns=%lld\n", delay_ns);
+	}
+#endif
 	lockdep_assert_held(&cpu_base->lock);
 
 	debug_deactivate(timer);
-- 
2.41.0