Re: [PATCH] x86/nmi: Ignore negative NMI handler durations

[Peter Zijlstra]

On Tue, Oct 27, 2026 at 03:43:51AM -0700, Breno Leitao wrote:
> I am seeing NMI handlers in the Meta fleet reported as running for
> about 584 years. Over 30 days, 11 AMD and Intel machines logged 637
> such lines, for example:
> 
>   AMD EPYC 9D25 (family 0x1a, model 0x11, stepping 0x0):
>   [ 1650.616627] INFO: NMI handler (nmi_cpu_backtrace_handler.llvm.9643156322683129580) took too long to run: 18446744073709.551 msecs
> 
>   Intel Xeon Platinum 8321HC (family 0x6, model 0x55, stepping 0xb):
>   [360448.230129] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 18446744071018.936 msecs
> 
>   Intel Xeon D-2191A (family 0x6, model 0x55, stepping 0x4):
>   [81787.188959] INFO: NMI handler (ghes_notify_nmi) took too long to run: 18446744073709.545 msecs

All these are 'recent' machine and should have a stable TSC :-( I hate
computers.

> nmi_handle() times each handler with two sched_clock() reads. When the
> second read is lower than the first, the u64 subtraction wraps, and
> nmi_check_duration() treats the result as a duration. In the three
> examples, the clock went back by less than 1 us, by 2.7 s and by about
> 6 us.
> 
> The wrapped value is also stored in action->max_duration. Every later
> real duration is smaller, so the handler is never reported again until
> the next boot.
> 
> Whatever makes the clock read lower, a negative difference is not a
> duration, so return before it is stored or reported. A clock that steps
> forward is not covered, since that cannot be told from a real stall.
> 
> A backwards clock is still worth knowing about, so print the size of
> the step once per boot. This uses pr_warn_once() rather than WARN, as a
> stack trace says nothing about the clock and panic_on_warn machines
> should not go down for it.
> 
> Fixes: 2ab00456ea8a ("x86: Warn when NMI handlers take large amounts of time")
> Cc: stable@xxxxxxxxxxxxxxx
> Cc: Paul E. McKenney <paulmck@xxxxxxxxxx>
> Signed-off-by: Breno Leitao <leitao@xxxxxxxxxx>
> ---
>  arch/x86/kernel/nmi.c | 8 ++++++++
>  1 file changed, 8 insertions(+)
> 
> diff --git a/arch/x86/kernel/nmi.c b/arch/x86/kernel/nmi.c
> index aae7254774680..57a0dab1ec7a9 100644
> --- a/arch/x86/kernel/nmi.c
> +++ b/arch/x86/kernel/nmi.c
> @@ -130,6 +130,14 @@ static void nmi_check_duration(struct nmiaction *action, u64 duration, struct pt
>  {
>  	int remainder_ns, decimal_msecs;
>  
> +	/* sched_clock() went backwards? */
> +	if ((s64)duration < 0) {
> +		pr_warn_once("NMI handler (%ps): sched_clock() went backwards by %lld ns on CPU%d\n",
> +			     action->handler, -(s64)duration,
> +			     smp_processor_id());
> +		return;
> +	}

Fair enough I suppose. Thanks