Re: [PATCH 04/12] time: Add debugging checks to warn if we see delays

[Ingo Molnar <mingo@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