[dm-devel] [PATCH 2/4] dm stats: support precise timestamps

[Mike Snitzer]

On Tue, Jun 09 2015 at  5:21pm -0400,
Mikulas Patocka <mpatocka at redhat.com> wrote:

> This patch makes it possible to use precise timestamps with nanosecond
> granularity in dm statistics.
> 
> Signed-off-by: Mikulas Patocka <mpatocka at redhat.com>
> 
> ---
>  Documentation/device-mapper/statistics.txt |   25 ++++-
>  drivers/md/dm-stats.c                      |  139 +++++++++++++++++++++--------
>  drivers/md/dm-stats.h                      |    4 
>  3 files changed, 125 insertions(+), 43 deletions(-)
> 
> Index: linux-4.1-rc7/drivers/md/dm-stats.c
> ===================================================================
> --- linux-4.1-rc7.orig/drivers/md/dm-stats.c	2015-06-08 16:02:27.000000000 +0200
> +++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-08 16:38:43.000000000 +0200
> @@ -33,13 +33,14 @@ struct dm_stat_percpu {
>  
>  struct dm_stat_shared {
>  	atomic_t in_flight[2];
> -	unsigned long stamp;
> +	unsigned long long stamp;
>  	struct dm_stat_percpu tmp;
>  };
>  
>  struct dm_stat {
>  	struct list_head list_entry;
>  	int id;
> +	unsigned stat_flags;
>  	size_t n_entries;
>  	sector_t start;
>  	sector_t end;
> @@ -53,6 +54,8 @@ struct dm_stat {
>  	struct dm_stat_shared stat_shared[0];
>  };
>  
> +#define STAT_PRECISE_TIMESTAMPS		1
> +
>  struct dm_stats_last_position {
>  	sector_t last_sector;
>  	unsigned last_rw;
> @@ -227,7 +230,8 @@ void dm_stats_cleanup(struct dm_stats *s
>  }
>  
>  static int dm_stats_create(struct dm_stats *stats, sector_t start, sector_t end,
> -			   sector_t step, const char *program_id, const char *aux_data,
> +			   sector_t step, unsigned stat_flags,
> +			   const char *program_id, const char *aux_data,
>  			   void (*suspend_callback)(struct mapped_device *),
>  			   void (*resume_callback)(struct mapped_device *),
>  			   struct mapped_device *md)
> @@ -268,6 +272,7 @@ static int dm_stats_create(struct dm_sta
>  	if (!s)
>  		return -ENOMEM;
>  
> +	s->stat_flags = stat_flags;
>  	s->n_entries = n_entries;
>  	s->start = start;
>  	s->end = end;
> @@ -417,15 +422,22 @@ static int dm_stats_list(struct dm_stats
>  	return 1;
>  }
>  
> -static void dm_stat_round(struct dm_stat_shared *shared, struct dm_stat_percpu *p)
> +static void dm_stat_round(struct dm_stat *s, struct dm_stat_shared *shared,
> +			  struct dm_stat_percpu *p)
>  {
>  	/*
>  	 * This is racy, but so is part_round_stats_single.
>  	 */
> -	unsigned long now = jiffies;
> -	unsigned in_flight_read;
> -	unsigned in_flight_write;
> -	unsigned long difference = now - shared->stamp;
> +	unsigned long long now, difference;
> +	unsigned in_flight_read, in_flight_write;
> +
> +	if (likely(!(s->stat_flags & STAT_PRECISE_TIMESTAMPS))) {
> +		now = jiffies;
> +	} else {
> +		now = ktime_to_ns(ktime_get());
> +	}
> +
> +	difference = now - shared->stamp;
>  
>  	if (!difference)
>  		return;

Here 'difference' is in nanosecond resolution if STAT_PRECISE_TIMESTAMPS

> @@ -646,11 +673,15 @@ static int dm_stats_clear(struct dm_stat
>  /*
>   * This is like jiffies_to_msec, but works for 64-bit values.
>   */
> -static unsigned long long dm_jiffies_to_msec64(unsigned long long j)
> +static unsigned long long dm_jiffies_to_msec64(struct dm_stat *s, unsigned long long j)
>  {
> -	unsigned long long result = 0;
> +	unsigned long long result;
>  	unsigned mult;
>  
> +	if (s->stat_flags & STAT_PRECISE_TIMESTAMPS)
> +		return j;
> +
> +	result = 0;
>  	if (j)
>  		result = jiffies_to_msecs(j & 0x3fffff);
>  	if (j >= 1 << 22) {

Yet here you aren't converting ns to ms...

> @@ -712,16 +743,16 @@ static int dm_stats_print(struct dm_stat
>  		       shared->tmp.ios[READ],
>  		       shared->tmp.merges[READ],
>  		       shared->tmp.sectors[READ],
> -		       dm_jiffies_to_msec64(shared->tmp.ticks[READ]),
> +		       dm_jiffies_to_msec64(s, shared->tmp.ticks[READ]),
>  		       shared->tmp.ios[WRITE],
>  		       shared->tmp.merges[WRITE],
>  		       shared->tmp.sectors[WRITE],
> -		       dm_jiffies_to_msec64(shared->tmp.ticks[WRITE]),
> +		       dm_jiffies_to_msec64(s, shared->tmp.ticks[WRITE]),
>  		       dm_stat_in_flight(shared),
> -		       dm_jiffies_to_msec64(shared->tmp.io_ticks_total),
> -		       dm_jiffies_to_msec64(shared->tmp.time_in_queue),
> -		       dm_jiffies_to_msec64(shared->tmp.io_ticks[READ]),
> -		       dm_jiffies_to_msec64(shared->tmp.io_ticks[WRITE]));
> +		       dm_jiffies_to_msec64(s, shared->tmp.io_ticks_total),
> +		       dm_jiffies_to_msec64(s, shared->tmp.time_in_queue),
> +		       dm_jiffies_to_msec64(s, shared->tmp.io_ticks[READ]),
> +		       dm_jiffies_to_msec64(s, shared->tmp.io_ticks[WRITE]));
>  
>  		if (unlikely(sz + 1 >= maxlen))
>  			goto buffer_overflow;

So the printed stats won't actually be in msec.

Or am I missing something?