From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S1752667AbbCLGcc (ORCPT <rfc822;w@1wt.eu>);
	Thu, 12 Mar 2015 02:32:32 -0400
Received: from mail-wi0-f181.google.com ([209.85.212.181]:46743 "EHLO
	mail-wi0-f181.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1751759AbbCLGcb (ORCPT
	<rfc822;linux-kernel@vger.kernel.org>);
	Thu, 12 Mar 2015 02:32:31 -0400
Date: Thu, 12 Mar 2015 07:32:25 +0100
From: Ingo Molnar <mingo@kernel.org>
To: John Stultz <john.stultz@linaro.org>
Cc: lkml <linux-kernel@vger.kernel.org>, Dave Jones <davej@codemonkey.org.uk>,
        Linus Torvalds <torvalds@linux-foundation.org>,
        Thomas Gleixner <tglx@linutronix.de>,
        Richard Cochran <richardcochran@gmail.com>,
        Prarit Bhargava <prarit@redhat.com>,
        Stephen Boyd <sboyd@codeaurora.org>,
        Peter Zijlstra <peterz@infradead.org>
Subject: Re: [PATCH 04/12] time: Add debugging checks to warn if we see delays
Message-ID: <20150312063224.GB13221@gmail.com>
References: <1426133800-29329-1-git-send-email-john.stultz@linaro.org>
 <1426133800-29329-5-git-send-email-john.stultz@linaro.org>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <1426133800-29329-5-git-send-email-john.stultz@linaro.org>
User-Agent: Mutt/1.5.23 (2014-03-12)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org


* John Stultz <john.stultz@linaro.org> wrote:

> Recently there's been some request for better sanity
> checking in the time code, so that its more clear
> when something is going wrong since timekeeping issues
> could manifest in a large number of strange ways with
> various subsystems.
> 
> Thus, this patch adds some extra infrastructure to
> add a check update_wall_time() to print warnings if we
> see the call delayed beyond the max_cycles overflow
> point, or beyond the clocksource max_idle_ns value
> which is currently 50% of the overflow point.
> 
> This extra infrastructure is conditionalized
> behind a new CONFIG_DEBUG_TIMEKEEPING option
> also added in this patch.
> 
> Tested this a bit by halting qemu for specified
> lengths of time to trigger the warnings.

> +static void timekeeping_check_update(struct timekeeper *tk, cycle_t offset)
> +{
> +
> +	cycle_t max_cycles = tk->tkr.clock->max_cycles;
> +	const char *name = tk->tkr.clock->name;
> +
> +	if (offset > max_cycles) {
> +		printk_deferred("ERROR: cycle offset (%lld) is larger than  allowed %s max_cycles (%lld)\n",
> +					offset, name, max_cycles);
> +	} else {
> +		if (offset > (max_cycles >> 1)) {
> +			printk_deferred("WARNING: cycle offset (%lld) is past the %s 50%% safety margin (%lld)\n",
> +					offset, name, max_cycles>>1);

Since we don't know the intensity with which these warnings will 
trigger on various systems, I've adjusted the messages a bit:

               printk_deferred("WARNING: timekeeping: cycle offset (%lld) is larger than allowed by '%s' max_cycles (%lld)\n",
                               offset, name, max_cycles);

               printk_deferred("INFO: timekeeping: cycle offset (%lld) is past the '%s' 50%% safety margin (%lld)\n",
                               offset, name, max_cycles>>1);

'INFO:' / 'WARNING:' is more in line with how we warn about various 
problems in kernel code.

We can upgrade this to 'WARNING:' / 'BUG:' pair once we are confident 
that most clocksources are doing OK.

I also improved the messages to make it apparent when we are printing 
a clocksource name and removed extra spaces from the message, etc. See 
the tip commit log notification email for details.

Thanks,

	Ingo