Re: [v3][PATCH 2/4] x86: warn when NMI handlers take large amountsof time

[Ingo Molnar]

* Dave Hansen <dave@xxxxxxxx> wrote:

> @@ -96,8 +106,24 @@ static int __kprobes nmi_handle(unsigned
>  	 * can be latched at any given time.  Walk the whole list
>  	 * to handle those situations.
>  	 */
> -	list_for_each_entry_rcu(a, &desc->head, list)
> +	list_for_each_entry_rcu(a, &desc->head, list) {
> +		u64 before, delta, whole_msecs;
> +		int decimal_msecs;
> +
> +		before = local_clock();
>  		handled += a->handler(type, regs);
> +		delta = local_clock() - before;
> +
> +		if (delta < nmi_longest_ns)
> +			continue;
> +
> +		nmi_longest_ns = delta;
> +		whole_msecs = delta / (1000 * 1000);
> +		decimal_msecs = (delta / 1000) % 1000;
> +		printk_ratelimited(KERN_INFO
> +			"INFO: NMI handler took too long to run: "
> +			"%lld.%03d msecs\n", whole_msecs, decimal_msecs);
> +	}

One more thing, would it make sense to print the symbol name of the 
->handler here? That way the message would be more actionable:

	INFO: NMI handler (nmi_handler_foo) took too long to run: 12.613 msecs

(Note, printk() has a '%ps' format string extension to print function 
pointer symbolic names, so it's easy to add.)

Thanks,

	Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/