Re: [PATCH 07/12] time: Add warnings when overflows or underflows are observed

[Ingo Molnar <mingo@kernel.org>]

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

> It was suggested that the underflow/overflow protection
> should probably throw some sort of warning out, rather
> then just silently fixing the issue.
> 
> So this patch adds some warnings here. The flag variables
> used are not protected by locks, but since we can't print
> from the reading functions, just being able to say we
> saw an issue in the update interval is useful enough,
> and can be slightly racy without real consequence.

> + * These simple flag variables are managed
> + * without locks, which is racy, but ok since
> + * we don't really care about being super
> + * precise about how many events were seen,
> + * just that a problem was observed.
> + */
> +static int timekeeping_underflow_seen;
> +static int timekeeping_overflow_seen;
> +
> +/* last_warning is only modified under the timekeeping lock */
> +static long timekeeping_last_warning;
> +
>  static void timekeeping_check_update(struct timekeeper *tk, cycle_t offset)
>  {
>  
> @@ -134,28 +148,62 @@ static void timekeeping_check_update(struct timekeeper *tk, cycle_t offset)
>  					offset, name, max_cycles>>1);
>  		}
>  	}
> +
> +	if (timekeeping_underflow_seen) {
> +		if (jiffies - timekeeping_last_warning > WARNING_FREQ) {
> +			printk_deferred("WARNING: Clocksource %s underflow observed. You should report\n", name);
> +			printk_deferred("         this, consider using a different clocksource.\n");
> +			timekeeping_last_warning = jiffies;
> +		}
> +		timekeeping_underflow_seen = 0;
> +	}
> +
> +	if (timekeeping_overflow_seen) {
> +		if (jiffies - timekeeping_last_warning > WARNING_FREQ) {
> +			printk_deferred("WARNING: Clocksource %s overflow observed. You should report\n", name);
> +			printk_deferred("         this, consider using a different clocksource.\n");
> +			timekeeping_last_warning = jiffies;
> +		}
> +		timekeeping_overflow_seen = 0;
> +	}
>  }
>  
>  static inline cycle_t timekeeping_get_delta(struct tk_read_base *tkr)
>  {
> -	cycle_t cycle_now, delta;
> +	cycle_t now, last, mask, max, delta;
> +	unsigned int seq;
>  
> -	/* read clocksource */
> -	cycle_now = tkr->read(tkr->clock);
> +	/*
> +	 * Since we're called holding a seqlock, the data may shift
> +	 * under us while we're doing the calculation. This can cause
> +	 * false positives, since we'd note a problem but throw the
> +	 * results away. So nest another seqlock here to atomically
> +	 * grab the points we are checking with.
> +	 */
> +	do {
> +		seq = read_seqcount_begin(&tk_core.seq);
> +		now = tkr->read(tkr->clock);
> +		last = tkr->cycle_last;
> +		mask = tkr->mask;
> +		max = tkr->clock->max_cycles;
> +	} while (read_seqcount_retry(&tk_core.seq, seq));
>  
> -	/* calculate the delta since the last update_wall_time */
> -	delta = clocksource_delta(cycle_now, tkr->cycle_last, tkr->mask);
> +	delta = clocksource_delta(now, last, mask);
>  
>  	/*
>  	 * Try to catch underflows by checking if we are seeing small
>  	 * mask-relative negative values.
>  	 */
> -	if (unlikely((~delta & tkr->mask) < (tkr->mask >> 3)))
> +	if (unlikely((~delta & mask) < (mask >> 3))) {
> +		timekeeping_underflow_seen = 1;
>  		delta = 0;
> +	}
>  
>  	/* Cap delta value to the max_cycles values to avoid mult overflows */
> -	if (unlikely(delta > tkr->clock->max_cycles))
> +	if (unlikely(delta > max)) {
> +		timekeeping_overflow_seen = 1;
>  		delta = tkr->clock->max_cycles;
> +	}

Please add the flags as new fields in the 'struct tk_read_base' data 
structure in include/linux/timekeeper_internal.h - we don't want to go 
back to the old pattern of adding globals to the timekeeping code, 
even if they are just for debugging!

also, timekeeping_check_update() should pass in 'struct tk_read_base', 
not 'struct timekeeper' - it's really only using the tkr bits and 
doing this change would make it similar to timekeeping_get_delta(). It 
would also shorten:

        cycle_t max_cycles = tk->tkr.clock->max_cycles;
        const char *name = tk->tkr.clock->name;

to the more natural looking:

        cycle_t max_cycles = tkr->clock->max_cycles;
        const char *name = tkr->clock->name;

hm?

Thanks,

	Ingo