[PATCH 0/4] Integrate dm-latency functionality to dm-statistics

[PATCH 0/4] Integrate dm-latency functionality to dm-statistics

[Mikulas Patocka]

Hi

Here I'm sending patches that add funcionality provided by dm-latency into 
dm-statistics framework. Dm-latency was introduced in this post 
https://www.redhat.com/archives/dm-devel/2015-February/msg00158.html , 
however, there is already similar framework dm-statistics in the kernel. 
In order to have cleaner and easier to maintain code, it is better to 
integrate dm-latency functionality into dm-statistics, rather than having 
two frameworks that do similar things.

This patch series makes these changes:
* it is possible to use precise time measurement with nanosecond 
  granularity (previously, time was measured in jiffies)
* it is possible to collect histogram of latencies. The histogram 
  boundaries may be selected by the user and there is unlimited number of 
  possible boundaries (in dm-latency, the histogram boundaries were fixed)
* it is possible to use dm-statistics on multipath

The documentation of these extensions is in 
Documentation/device-mapper/statistics.txt

I'd like to ask people who designed dm-latency to check this patchset, try 
to use it and tell us if it provides sufficient functionality to them (the 
indended functinality of dm-latency was to predict hard disk failures from 
i/o request latency histogram).

Mikulas

[PATCH 1/4] dm-statistics: better argument validation

[Mikulas Patocka]

If the number_of_areas argument was zero, the kernel would crash on
div-by-zero. This patch fixes it.

Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>
Cc: stable@vger.kernel.org	# v3.12+

---
 drivers/md/dm-stats.c |    2 ++
 1 file changed, 2 insertions(+)

Index: linux-4.1-rc6/drivers/md/dm-stats.c
===================================================================
--- linux-4.1-rc6.orig/drivers/md/dm-stats.c	2015-06-05 15:39:58.000000000 +0200
+++ linux-4.1-rc6/drivers/md/dm-stats.c	2015-06-05 15:42:09.000000000 +0200
@@ -795,6 +795,8 @@ static int message_stats_create(struct m
 		return -EINVAL;
 
 	if (sscanf(argv[2], "/%u%c", &divisor, &dummy) == 1) {
+		if (!divisor)
+			return -EINVAL;
 		step = end - start;
 		if (do_div(step, divisor))
 			step++;

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

[Mikulas Patocka]

This patch makes it possible to use precise timestamps with nanosecond
granularity in dm statistics.

Signed-off-by: Mikulas Patocka <mpatocka@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;
@@ -443,8 +455,9 @@ static void dm_stat_round(struct dm_stat
 }
 
 static void dm_stat_for_entry(struct dm_stat *s, size_t entry,
-			      unsigned long bi_rw, sector_t len, bool merged,
-			      bool end, unsigned long duration)
+			      unsigned long bi_rw, sector_t len,
+			      struct dm_stats_aux *stats_aux, bool end,
+			      unsigned long duration_jiffies)
 {
 	unsigned long idx = bi_rw & REQ_WRITE;
 	struct dm_stat_shared *shared = &s->stat_shared[entry];
@@ -474,15 +487,18 @@ static void dm_stat_for_entry(struct dm_
 	p = &s->stat_percpu[smp_processor_id()][entry];
 
 	if (!end) {
-		dm_stat_round(shared, p);
+		dm_stat_round(s, shared, p);
 		atomic_inc(&shared->in_flight[idx]);
 	} else {
-		dm_stat_round(shared, p);
+		dm_stat_round(s, shared, p);
 		atomic_dec(&shared->in_flight[idx]);
 		p->sectors[idx] += len;
 		p->ios[idx] += 1;
-		p->merges[idx] += merged;
-		p->ticks[idx] += duration;
+		p->merges[idx] += stats_aux->merged;
+		if (!(s->stat_flags & STAT_PRECISE_TIMESTAMPS))
+			p->ticks[idx] += duration_jiffies;
+		else
+			p->ticks[idx] += stats_aux->duration_ns;
 	}
 
 #if BITS_PER_LONG == 32
@@ -494,7 +510,7 @@ static void dm_stat_for_entry(struct dm_
 
 static void __dm_stat_bio(struct dm_stat *s, unsigned long bi_rw,
 			  sector_t bi_sector, sector_t end_sector,
-			  bool end, unsigned long duration,
+			  bool end, unsigned long duration_jiffies,
 			  struct dm_stats_aux *stats_aux)
 {
 	sector_t rel_sector, offset, todo, fragment_len;
@@ -523,7 +539,7 @@ static void __dm_stat_bio(struct dm_stat
 		if (fragment_len > s->step - offset)
 			fragment_len = s->step - offset;
 		dm_stat_for_entry(s, entry, bi_rw, fragment_len,
-				  stats_aux->merged, end, duration);
+				  stats_aux, end, duration_jiffies);
 		todo -= fragment_len;
 		entry++;
 		offset = 0;
@@ -532,11 +548,13 @@ static void __dm_stat_bio(struct dm_stat
 
 void dm_stats_account_io(struct dm_stats *stats, unsigned long bi_rw,
 			 sector_t bi_sector, unsigned bi_sectors, bool end,
-			 unsigned long duration, struct dm_stats_aux *stats_aux)
+			 unsigned long duration_jiffies,
+			 struct dm_stats_aux *stats_aux)
 {
 	struct dm_stat *s;
 	sector_t end_sector;
 	struct dm_stats_last_position *last;
+	bool got_precise_time;
 
 	if (unlikely(!bi_sectors))
 		return;
@@ -560,8 +578,17 @@ void dm_stats_account_io(struct dm_stats
 
 	rcu_read_lock();
 
-	list_for_each_entry_rcu(s, &stats->list, list_entry)
-		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration, stats_aux);
+	got_precise_time = false;
+	list_for_each_entry_rcu(s, &stats->list, list_entry) {
+		if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
+			if (!end)
+				stats_aux->duration_ns = ktime_to_ns(ktime_get());
+			else
+				stats_aux->duration_ns = ktime_to_ns(ktime_get()) - stats_aux->duration_ns;
+			got_precise_time = true;
+		}
+		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration_jiffies, stats_aux);
+	}
 
 	rcu_read_unlock();
 }
@@ -574,7 +601,7 @@ static void __dm_stat_init_temporary_per
 
 	local_irq_disable();
 	p = &s->stat_percpu[smp_processor_id()][x];
-	dm_stat_round(shared, p);
+	dm_stat_round(s, shared, p);
 	local_irq_enable();
 
 	memset(&shared->tmp, 0, sizeof(shared->tmp));
@@ -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) {
@@ -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;
@@ -772,21 +803,31 @@ static int message_stats_create(struct m
 	unsigned long long start, end, len, step;
 	unsigned divisor;
 	const char *program_id, *aux_data;
+	unsigned stat_flags = 0;
+
+	struct dm_arg_set as, as_backup;
+	const char *a;
+	unsigned feature_args;
 
 	/*
 	 * Input format:
-	 *   <range> <step> [<program_id> [<aux_data>]]
+	 *   <range> <step> [<extra_parameters> <parameters>] [<program_id> [<aux_data>]]
 	 */
 
-	if (argc < 3 || argc > 5)
+	if (argc < 3)
 		return -EINVAL;
 
-	if (!strcmp(argv[1], "-")) {
+	as.argc = argc;
+	as.argv = argv;
+	dm_consume_args(&as, 1);
+
+	a = dm_shift_arg(&as);
+	if (!strcmp(a, "-")) {
 		start = 0;
 		len = dm_get_size(md);
 		if (!len)
 			len = 1;
-	} else if (sscanf(argv[1], "%llu+%llu%c", &start, &len, &dummy) != 2 ||
+	} else if (sscanf(a, "%llu+%llu%c", &start, &len, &dummy) != 2 ||
 		   start != (sector_t)start || len != (sector_t)len)
 		return -EINVAL;
 
@@ -794,7 +835,8 @@ static int message_stats_create(struct m
 	if (start >= end)
 		return -EINVAL;
 
-	if (sscanf(argv[2], "/%u%c", &divisor, &dummy) == 1) {
+	a = dm_shift_arg(&as);
+	if (sscanf(a, "/%u%c", &divisor, &dummy) == 1) {
 		if (!divisor)
 			return -EINVAL;
 		step = end - start;
@@ -802,18 +844,39 @@ static int message_stats_create(struct m
 			step++;
 		if (!step)
 			step = 1;
-	} else if (sscanf(argv[2], "%llu%c", &step, &dummy) != 1 ||
+	} else if (sscanf(a, "%llu%c", &step, &dummy) != 1 ||
 		   step != (sector_t)step || !step)
 		return -EINVAL;
 
+	as_backup = as;
+	a = dm_shift_arg(&as);
+	if (a && sscanf(a, "%u%c", &feature_args, &dummy) == 1) {
+		while (feature_args--) {
+			a = dm_shift_arg(&as);
+			if (!a)
+				return -EINVAL;
+			if (!strcasecmp(a, "precise_timestamps"))
+				stat_flags |= STAT_PRECISE_TIMESTAMPS;
+			else
+				return -EINVAL;
+		}
+	} else {
+		as = as_backup;
+	}
+
 	program_id = "-";
 	aux_data = "-";
 
-	if (argc > 3)
-		program_id = argv[3];
+	a = dm_shift_arg(&as);
+	if (a)
+		program_id = a;
+
+	a = dm_shift_arg(&as);
+	if (a)
+		aux_data = a;
 
-	if (argc > 4)
-		aux_data = argv[4];
+	if (as.argc)
+		return -EINVAL;
 
 	/*
 	 * If a buffer overflow happens after we created the region,
@@ -825,7 +888,7 @@ static int message_stats_create(struct m
 	if (dm_message_test_buffer_overflow(result, maxlen))
 		return 1;
 
-	id = dm_stats_create(dm_get_stats(md), start, end, step, program_id, aux_data,
+	id = dm_stats_create(dm_get_stats(md), start, end, step, stat_flags, program_id, aux_data,
 			     dm_internal_suspend_fast, dm_internal_resume_fast, md);
 	if (id < 0)
 		return id;
Index: linux-4.1-rc7/drivers/md/dm-stats.h
===================================================================
--- linux-4.1-rc7.orig/drivers/md/dm-stats.h	2015-06-08 16:01:30.000000000 +0200
+++ linux-4.1-rc7/drivers/md/dm-stats.h	2015-06-08 16:02:27.000000000 +0200
@@ -18,6 +18,7 @@ struct dm_stats {
 
 struct dm_stats_aux {
 	bool merged;
+	unsigned long long duration_ns;
 };
 
 void dm_stats_init(struct dm_stats *st);
@@ -30,7 +31,8 @@ int dm_stats_message(struct mapped_devic
 
 void dm_stats_account_io(struct dm_stats *stats, unsigned long bi_rw,
 			 sector_t bi_sector, unsigned bi_sectors, bool end,
-			 unsigned long duration, struct dm_stats_aux *aux);
+			 unsigned long duration_jiffies,
+			 struct dm_stats_aux *aux);
 
 static inline bool dm_stats_used(struct dm_stats *st)
 {
Index: linux-4.1-rc7/Documentation/device-mapper/statistics.txt
===================================================================
--- linux-4.1-rc7.orig/Documentation/device-mapper/statistics.txt	2015-06-08 16:38:59.000000000 +0200
+++ linux-4.1-rc7/Documentation/device-mapper/statistics.txt	2015-06-08 17:00:05.000000000 +0200
@@ -13,9 +13,13 @@ the range specified.
 The I/O statistics counters for each step-sized area of a region are
 in the same format as /sys/block/*/stat or /proc/diskstats (see:
 Documentation/iostats.txt).  But two extra counters (12 and 13) are
-provided: total time spent reading and writing in milliseconds.	 All
-these counters may be accessed by sending the @stats_print message to
-the appropriate DM device via dmsetup.
+provided: total time spent reading and writing.  All these counters may
+be accessed by sending the @stats_print message to the appropriate DM
+device via dmsetup.
+
+The reported times are in milliseconds and the granularity depends on
+the kernel ticks.  When the option precise_timestamps is used, the
+reported times are in nanoseconds.
 
 Each region has a corresponding unique identifier, which we call a
 region_id, that is assigned when the region is created.	 The region_id
@@ -33,7 +37,9 @@ memory is used by reading
 Messages
 ========
 
-    @stats_create <range> <step> [<program_id> [<aux_data>]]
+    @stats_create <range> <step>
+    		[<number_of_optional_arguments> <optional_arguments>...]
+		[<program_id> [<aux_data>]]
 
 	Create a new region and return the region_id.
 
@@ -48,6 +54,17 @@ Messages
 	  "/<number_of_areas>" - the range is subdivided into the specified
 				 number of areas.
 
+	<number_of_optional_arguments>
+	  The number of optional arguments
+
+	<optional_arguments>
+	  The following optional arguments are supported
+	  precise_timestamps - use precise timer with nanosecond resolution
+	  	instead of the "jiffies" variable.  When this argument is
+		used, the resulting times are in nanoseconds instead of
+		milliseconds.  Precise timestamps are a little bit slower
+		to obtain than jiffies-based timestamps.
+
 	<program_id>
 	  An optional parameter.  A name that uniquely identifies
 	  the userspace owner of the range.  This groups ranges together

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

[Mike Snitzer]

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

> This patch makes it possible to use precise timestamps with nanosecond
> granularity in dm statistics.
> 
> Signed-off-by: Mikulas Patocka <mpatocka@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?

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

[Mikulas Patocka]

On Wed, 10 Jun 2015, Mike Snitzer wrote:

> On Tue, Jun 09 2015 at  5:21pm -0400,
> Mikulas Patocka <mpatocka@redhat.com> wrote:
> 
> > This patch makes it possible to use precise timestamps with nanosecond
> > granularity in dm statistics.
> > 
> > Signed-off-by: Mikulas Patocka <mpatocka@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

Yes.

> > @@ -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...

That function is converting jiffies to ms. When STAT_PRECISE_TIMESTAMPS is 
not set, the internal times are kept in jiffies and they are converted to 
ms when being printed. When STAT_PRECISE_TIMESTAMPS is set, the internal 
times are kept in ns and no conversion is done when they are printed.

> > @@ -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?

If STAT_PRECISE_TIMESTAMPS is not set, the printed values are in ms, if it 
is set, they are in ns.

Mikulas

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

[Mike Snitzer]

On Wed, Jun 10 2015 at  1:33pm -0400,
Mikulas Patocka <mpatocka@redhat.com> wrote:

> 
> 
> On Wed, 10 Jun 2015, Mike Snitzer wrote:
> 
> > On Tue, Jun 09 2015 at  5:21pm -0400,
> > Mikulas Patocka <mpatocka@redhat.com> wrote:
> > 
> > > This patch makes it possible to use precise timestamps with nanosecond
> > > granularity in dm statistics.
> > > 
> > > Signed-off-by: Mikulas Patocka <mpatocka@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
> 
> Yes.
> 
> > > @@ -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...
> 
> That function is converting jiffies to ms. When STAT_PRECISE_TIMESTAMPS is 
> not set, the internal times are kept in jiffies and they are converted to 
> ms when being printed. When STAT_PRECISE_TIMESTAMPS is set, the internal 
> times are kept in ns and no conversion is done when they are printed.
> 
> > > @@ -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?
> 
> If STAT_PRECISE_TIMESTAMPS is not set, the printed values are in ms, if it 
> is set, they are in ns.

OK, makes sense.  Otherwise we'd be losing the precision (which defeats
the purpose of this exercise).  Thanks.

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

[Coly Li]

在 15/6/10 上午5:21, Mikulas Patocka 写道:
> This patch makes it possible to use precise timestamps with nanosecond
> granularity in dm statistics.
>
> Signed-off-by: Mikulas Patocka <mpatocka@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 {
>  
[snip]
> @@ -560,8 +578,17 @@ void dm_stats_account_io(struct dm_stats
>  
>  	rcu_read_lock();
>  
> -	list_for_each_entry_rcu(s, &stats->list, list_entry)
> -		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration, stats_aux);
> +	got_precise_time = false;
> +	list_for_each_entry_rcu(s, &stats->list, list_entry) {
> +		if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
> +			if (!end)
> +				stats_aux->duration_ns = ktime_to_ns(ktime_get());
> +			else
> +				stats_aux->duration_ns = ktime_to_ns(ktime_get()) - stats_aux->duration_ns;
> +			got_precise_time = true;
> +		}
There are many conditions user space processes may query the global
timer resource frequently. ktime_get() will call spin_lock when
accessing global timer resource, calling ktime_get() for each list entry
might introduce locking contention when stats->list is quite large. A
satisfied solution might be something like this,

+    now = ktime_to_ns(ktime_get());
+    list_for_each_entry_rcu(s, &stats->list, list_entry) {
+        if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
+            if (!end)
+                stats_aux->duration_ns = now;
+            else
+                stats_aux->duration_ns = now - stats_aux->duration_ns;
+            got_precise_time = true;
+        }

In this case the global timer could be access only once, locking
contention should be much less. Yes, it looks to be some inaccurate, but
for hard disk I/O latency measurement, the difference almost could be
ignored.
> +		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration_jiffies, stats_aux);
> +	}
>  
>  	rcu_read_unlock();
>  }
[snip]
> @@ -772,21 +803,31 @@ static int message_stats_create(struct m
>  	unsigned long long start, end, len, step;
>  	unsigned divisor;
>  	const char *program_id, *aux_data;
> +	unsigned stat_flags = 0;
> +
> +	struct dm_arg_set as, as_backup;
> +	const char *a;
> +	unsigned feature_args;
>  
>  	/*
>  	 * Input format:
> -	 *   <range> <step> [<program_id> [<aux_data>]]
> +	 *   <range> <step> [<extra_parameters> <parameters>] [<program_id> [<aux_data>]]
>  	 */
>  
> -	if (argc < 3 || argc > 5)
> +	if (argc < 3)
>  		return -EINVAL;
>  
> -	if (!strcmp(argv[1], "-")) {
> +	as.argc = argc;
> +	as.argv = argv;
> +	dm_consume_args(&as, 1);
> +
> +	a = dm_shift_arg(&as);
> +	if (!strcmp(a, "-")) {
>  		start = 0;
>  		len = dm_get_size(md);
>  		if (!len)
>  			len = 1;
> -	} else if (sscanf(argv[1], "%llu+%llu%c", &start, &len, &dummy) != 2 ||
> +	} else if (sscanf(a, "%llu+%llu%c", &start, &len, &dummy) != 2 ||
>  		   start != (sector_t)start || len != (sector_t)len)
>  		return -EINVAL;
>  
> @@ -794,7 +835,8 @@ static int message_stats_create(struct m
>  	if (start >= end)
>  		return -EINVAL;
>  
> -	if (sscanf(argv[2], "/%u%c", &divisor, &dummy) == 1) {
> +	a = dm_shift_arg(&as);
> +	if (sscanf(a, "/%u%c", &divisor, &dummy) == 1) {
>  		if (!divisor)
>  			return -EINVAL;
>  		step = end - start;
> @@ -802,18 +844,39 @@ static int message_stats_create(struct m
>  			step++;
>  		if (!step)
>  			step = 1;
> -	} else if (sscanf(argv[2], "%llu%c", &step, &dummy) != 1 ||
> +	} else if (sscanf(a, "%llu%c", &step, &dummy) != 1 ||
>  		   step != (sector_t)step || !step)
>  		return -EINVAL;
>  
> +	as_backup = as;
> +	a = dm_shift_arg(&as);
> +	if (a && sscanf(a, "%u%c", &feature_args, &dummy) == 1) {
> +		while (feature_args--) {
> +			a = dm_shift_arg(&as);
> +			if (!a)
> +				return -EINVAL;
> +			if (!strcasecmp(a, "precise_timestamps"))
> +				stat_flags |= STAT_PRECISE_TIMESTAMPS;
> +			else
> +				return -EINVAL;
> +		}
> +	} else {
> +		as = as_backup;
> +	}
> +
>  	program_id = "-";
>  	aux_data = "-";
>  
> -	if (argc > 3)
> -		program_id = argv[3];
> +	a = dm_shift_arg(&as);
> +	if (a)
> +		program_id = a;
> +
> +	a = dm_shift_arg(&as);
> +	if (a)
> +		aux_data = a;
>  
> -	if (argc > 4)
> -		aux_data = argv[4];
> +	if (as.argc)
> +		return -EINVAL;
>  
If I could, I would simplify the design to remove the above changes in
message_stats_create(). Just my suggestion ...

[snip]

Coly

--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

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

[Mikulas Patocka]

On Sun, 14 Jun 2015, Coly Li wrote:

> ? 15/6/10 ??5:21, Mikulas Patocka ??:
> > This patch makes it possible to use precise timestamps with nanosecond
> > granularity in dm statistics.
> >
> > Signed-off-by: Mikulas Patocka <mpatocka@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 {
> >  
> [snip]
> > @@ -560,8 +578,17 @@ void dm_stats_account_io(struct dm_stats
> >  
> >  	rcu_read_lock();
> >  
> > -	list_for_each_entry_rcu(s, &stats->list, list_entry)
> > -		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration, stats_aux);
> > +	got_precise_time = false;
> > +	list_for_each_entry_rcu(s, &stats->list, list_entry) {
> > +		if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
> > +			if (!end)
> > +				stats_aux->duration_ns = ktime_to_ns(ktime_get());
> > +			else
> > +				stats_aux->duration_ns = ktime_to_ns(ktime_get()) - stats_aux->duration_ns;
> > +			got_precise_time = true;
> > +		}
> There are many conditions user space processes may query the global
> timer resource frequently. ktime_get() will call spin_lock when
> accessing global timer resource, calling ktime_get() for each list entry
> might introduce locking contention when stats->list is quite large.

The above code doesn't call ktime_get() for each list entry - it calls 
ktime_get() only once, then sets got_precise_time, and doesn't call it 
anymore.

> A satisfied solution might be something like this,
> 
> +    now = ktime_to_ns(ktime_get());
> +    list_for_each_entry_rcu(s, &stats->list, list_entry) {
> +        if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
> +            if (!end)
> +                stats_aux->duration_ns = now;
> +            else
> +                stats_aux->duration_ns = now - stats_aux->duration_ns;
> +            got_precise_time = true;
> +        }

This is worse that the previous code - this piece of code calls 
ktime_get() even if no list entry requires precise timestamps. The 
previous code called ktime_get() only if there is at least one list entry 
that has STAT_PRECISE_TIMESTAMPS set.

> In this case the global timer could be access only once, locking
> contention should be much less. Yes, it looks to be some inaccurate, but
> for hard disk I/O latency measurement, the difference almost could be
> ignored.
> > +		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration_jiffies, stats_aux);
> > +	}
> >  
> >  	rcu_read_unlock();
> >  }
> [snip]
> > @@ -772,21 +803,31 @@ static int message_stats_create(struct m
> >  	unsigned long long start, end, len, step;
> >  	unsigned divisor;
> >  	const char *program_id, *aux_data;
> > +	unsigned stat_flags = 0;
> > +
> > +	struct dm_arg_set as, as_backup;
> > +	const char *a;
> > +	unsigned feature_args;
> >  
> >  	/*
> >  	 * Input format:
> > -	 *   <range> <step> [<program_id> [<aux_data>]]
> > +	 *   <range> <step> [<extra_parameters> <parameters>] [<program_id> [<aux_data>]]
> >  	 */
> >  
> > -	if (argc < 3 || argc > 5)
> > +	if (argc < 3)
> >  		return -EINVAL;
> >  
> > -	if (!strcmp(argv[1], "-")) {
> > +	as.argc = argc;
> > +	as.argv = argv;
> > +	dm_consume_args(&as, 1);
> > +
> > +	a = dm_shift_arg(&as);
> > +	if (!strcmp(a, "-")) {
> >  		start = 0;
> >  		len = dm_get_size(md);
> >  		if (!len)
> >  			len = 1;
> > -	} else if (sscanf(argv[1], "%llu+%llu%c", &start, &len, &dummy) != 2 ||
> > +	} else if (sscanf(a, "%llu+%llu%c", &start, &len, &dummy) != 2 ||
> >  		   start != (sector_t)start || len != (sector_t)len)
> >  		return -EINVAL;
> >  
> > @@ -794,7 +835,8 @@ static int message_stats_create(struct m
> >  	if (start >= end)
> >  		return -EINVAL;
> >  
> > -	if (sscanf(argv[2], "/%u%c", &divisor, &dummy) == 1) {
> > +	a = dm_shift_arg(&as);
> > +	if (sscanf(a, "/%u%c", &divisor, &dummy) == 1) {
> >  		if (!divisor)
> >  			return -EINVAL;
> >  		step = end - start;
> > @@ -802,18 +844,39 @@ static int message_stats_create(struct m
> >  			step++;
> >  		if (!step)
> >  			step = 1;
> > -	} else if (sscanf(argv[2], "%llu%c", &step, &dummy) != 1 ||
> > +	} else if (sscanf(a, "%llu%c", &step, &dummy) != 1 ||
> >  		   step != (sector_t)step || !step)
> >  		return -EINVAL;
> >  
> > +	as_backup = as;
> > +	a = dm_shift_arg(&as);
> > +	if (a && sscanf(a, "%u%c", &feature_args, &dummy) == 1) {
> > +		while (feature_args--) {
> > +			a = dm_shift_arg(&as);
> > +			if (!a)
> > +				return -EINVAL;
> > +			if (!strcasecmp(a, "precise_timestamps"))
> > +				stat_flags |= STAT_PRECISE_TIMESTAMPS;
> > +			else
> > +				return -EINVAL;
> > +		}
> > +	} else {
> > +		as = as_backup;
> > +	}
> > +
> >  	program_id = "-";
> >  	aux_data = "-";
> >  
> > -	if (argc > 3)
> > -		program_id = argv[3];
> > +	a = dm_shift_arg(&as);
> > +	if (a)
> > +		program_id = a;
> > +
> > +	a = dm_shift_arg(&as);
> > +	if (a)
> > +		aux_data = a;
> >  
> > -	if (argc > 4)
> > -		aux_data = argv[4];
> > +	if (as.argc)
> > +		return -EINVAL;
> >  
> If I could, I would simplify the design to remove the above changes in
> message_stats_create(). Just my suggestion ...

I don't know what you mean - if you remove the above changes in 
message_stats_create - then obviously - the user will not be able to 
enable precise timestamps or histogram.

Mikulas

> [snip]
> 
> Coly
> 

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

[Coly Li]

在 15/6/15 下午9:04, Mikulas Patocka 写道:
>
> On Sun, 14 Jun 2015, Coly Li wrote:
>
>> ? 15/6/10 ??5:21, Mikulas Patocka ??:
>>> This patch makes it possible to use precise timestamps with nanosecond
>>> granularity in dm statistics.
>>>
>>> Signed-off-by: Mikulas Patocka <mpatocka@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 {
>>>  
>> [snip]
>>> @@ -560,8 +578,17 @@ void dm_stats_account_io(struct dm_stats
>>>  
>>>  	rcu_read_lock();
>>>  
>>> -	list_for_each_entry_rcu(s, &stats->list, list_entry)
>>> -		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration, stats_aux);
>>> +	got_precise_time = false;
>>> +	list_for_each_entry_rcu(s, &stats->list, list_entry) {
>>> +		if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
>>> +			if (!end)
>>> +				stats_aux->duration_ns = ktime_to_ns(ktime_get());
>>> +			else
>>> +				stats_aux->duration_ns = ktime_to_ns(ktime_get()) - stats_aux->duration_ns;
>>> +			got_precise_time = true;
>>> +		}
>> There are many conditions user space processes may query the global
>> timer resource frequently. ktime_get() will call spin_lock when
>> accessing global timer resource, calling ktime_get() for each list entry
>> might introduce locking contention when stats->list is quite large.
> The above code doesn't call ktime_get() for each list entry - it calls 
> ktime_get() only once, then sets got_precise_time, and doesn't call it 
> anymore.
>
>> A satisfied solution might be something like this,
>>
>> +    now = ktime_to_ns(ktime_get());
>> +    list_for_each_entry_rcu(s, &stats->list, list_entry) {
>> +        if (s->stat_flags & STAT_PRECISE_TIMESTAMPS && !got_precise_time) {
>> +            if (!end)
>> +                stats_aux->duration_ns = now;
>> +            else
>> +                stats_aux->duration_ns = now - stats_aux->duration_ns;
>> +            got_precise_time = true;
>> +        }
> This is worse that the previous code - this piece of code calls 
> ktime_get() even if no list entry requires precise timestamps. The 
> previous code called ktime_get() only if there is at least one list entry 
> that has STAT_PRECISE_TIMESTAMPS set.
Yes you are right, I made a mistake here.

>> In this case the global timer could be access only once, locking
>> contention should be much less. Yes, it looks to be some inaccurate, but
>> for hard disk I/O latency measurement, the difference almost could be
>> ignored.
>>> +		__dm_stat_bio(s, bi_rw, bi_sector, end_sector, end, duration_jiffies, stats_aux);
>>> +	}
>>>  
>>>  	rcu_read_unlock();
>>>  }
>> [snip]
>>> @@ -772,21 +803,31 @@ static int message_stats_create(struct m
>>>  	unsigned long long start, end, len, step;
>>>  	unsigned divisor;
>>>  	const char *program_id, *aux_data;
>>> +	unsigned stat_flags = 0;
>>> +
>>> +	struct dm_arg_set as, as_backup;
>>> +	const char *a;
>>> +	unsigned feature_args;
>>>  
>>>  	/*
>>>  	 * Input format:
>>> -	 *   <range> <step> [<program_id> [<aux_data>]]
>>> +	 *   <range> <step> [<extra_parameters> <parameters>] [<program_id> [<aux_data>]]
>>>  	 */
>>>  
>>> -	if (argc < 3 || argc > 5)
>>> +	if (argc < 3)
>>>  		return -EINVAL;
>>>  
>>> -	if (!strcmp(argv[1], "-")) {
>>> +	as.argc = argc;
>>> +	as.argv = argv;
>>> +	dm_consume_args(&as, 1);
>>> +
>>> +	a = dm_shift_arg(&as);
>>> +	if (!strcmp(a, "-")) {
>>>  		start = 0;
>>>  		len = dm_get_size(md);
>>>  		if (!len)
>>>  			len = 1;
>>> -	} else if (sscanf(argv[1], "%llu+%llu%c", &start, &len, &dummy) != 2 ||
>>> +	} else if (sscanf(a, "%llu+%llu%c", &start, &len, &dummy) != 2 ||
>>>  		   start != (sector_t)start || len != (sector_t)len)
>>>  		return -EINVAL;
>>>  
>>> @@ -794,7 +835,8 @@ static int message_stats_create(struct m
>>>  	if (start >= end)
>>>  		return -EINVAL;
>>>  
>>> -	if (sscanf(argv[2], "/%u%c", &divisor, &dummy) == 1) {
>>> +	a = dm_shift_arg(&as);
>>> +	if (sscanf(a, "/%u%c", &divisor, &dummy) == 1) {
>>>  		if (!divisor)
>>>  			return -EINVAL;
>>>  		step = end - start;
>>> @@ -802,18 +844,39 @@ static int message_stats_create(struct m
>>>  			step++;
>>>  		if (!step)
>>>  			step = 1;
>>> -	} else if (sscanf(argv[2], "%llu%c", &step, &dummy) != 1 ||
>>> +	} else if (sscanf(a, "%llu%c", &step, &dummy) != 1 ||
>>>  		   step != (sector_t)step || !step)
>>>  		return -EINVAL;
>>>  
>>> +	as_backup = as;
>>> +	a = dm_shift_arg(&as);
>>> +	if (a && sscanf(a, "%u%c", &feature_args, &dummy) == 1) {
>>> +		while (feature_args--) {
>>> +			a = dm_shift_arg(&as);
>>> +			if (!a)
>>> +				return -EINVAL;
>>> +			if (!strcasecmp(a, "precise_timestamps"))
>>> +				stat_flags |= STAT_PRECISE_TIMESTAMPS;
>>> +			else
>>> +				return -EINVAL;
>>> +		}
>>> +	} else {
>>> +		as = as_backup;
>>> +	}
>>> +
>>>  	program_id = "-";
>>>  	aux_data = "-";
>>>  
>>> -	if (argc > 3)
>>> -		program_id = argv[3];
>>> +	a = dm_shift_arg(&as);
>>> +	if (a)
>>> +		program_id = a;
>>> +
>>> +	a = dm_shift_arg(&as);
>>> +	if (a)
>>> +		aux_data = a;
>>>  
>>> -	if (argc > 4)
>>> -		aux_data = argv[4];
>>> +	if (as.argc)
>>> +		return -EINVAL;
>>>  
>> If I could, I would simplify the design to remove the above changes in
>> message_stats_create(). Just my suggestion ...
> I don't know what you mean - if you remove the above changes in 
> message_stats_create - then obviously - the user will not be able to 
> enable precise timestamps or histogram.
I just suggest a simpler interface. Multiple boundaries might be over
designed here, maybe a pre-defined latency boundaries will make 90%+
users happy. How about just a "precise_timestamps" parameter and
allocate the array dynamically still ?

Coly

--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

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

[Vivek Goyal]

On Tue, Jun 09, 2015 at 05:21:39PM -0400, Mikulas Patocka wrote:

[..]
>  Messages
>  ========
>  
> -    @stats_create <range> <step> [<program_id> [<aux_data>]]
> +    @stats_create <range> <step>
> +    		[<number_of_optional_arguments> <optional_arguments>...]
> +		[<program_id> [<aux_data>]]
>  
>  	Create a new region and return the region_id.
>  
> @@ -48,6 +54,17 @@ Messages
>  	  "/<number_of_areas>" - the range is subdivided into the specified
>  				 number of areas.
>  
> +	<number_of_optional_arguments>
> +	  The number of optional arguments
> +
> +	<optional_arguments>
> +	  The following optional arguments are supported
> +	  precise_timestamps - use precise timer with nanosecond resolution
> +	  	instead of the "jiffies" variable.  When this argument is
> +		used, the resulting times are in nanoseconds instead of
> +		milliseconds.  Precise timestamps are a little bit slower
> +		to obtain than jiffies-based timestamps.
> +

Instead of "precise_timestams" will it make sense to call it
"nanosecond_timestamps" or "ns_timestamps".


>  	<program_id>
>  	  An optional parameter.  A name that uniquely identifies
>  	  the userspace owner of the range.  This groups ranges together

We are adding these new parameters/arguments in between existing parameters.
Will it break any of the existing scritps. Will it make sense to add these
new parameters at the end. It is more intuitive.

Also, I was wondering that why do we need to introduce this notion of
number of optional arguments. Can't we just introduce another optional
parameter [ns_timestamps]. That feels little simpler.

Thanks
Vivek

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

[Mikulas Patocka]

On Tue, 16 Jun 2015, Vivek Goyal wrote:

> On Tue, Jun 09, 2015 at 05:21:39PM -0400, Mikulas Patocka wrote:
> 
> [..]
> >  Messages
> >  ========
> >  
> > -    @stats_create <range> <step> [<program_id> [<aux_data>]]
> > +    @stats_create <range> <step>
> > +    		[<number_of_optional_arguments> <optional_arguments>...]
> > +		[<program_id> [<aux_data>]]
> >  
> >  	Create a new region and return the region_id.
> >  
> > @@ -48,6 +54,17 @@ Messages
> >  	  "/<number_of_areas>" - the range is subdivided into the specified
> >  				 number of areas.
> >  
> > +	<number_of_optional_arguments>
> > +	  The number of optional arguments
> > +
> > +	<optional_arguments>
> > +	  The following optional arguments are supported
> > +	  precise_timestamps - use precise timer with nanosecond resolution
> > +	  	instead of the "jiffies" variable.  When this argument is
> > +		used, the resulting times are in nanoseconds instead of
> > +		milliseconds.  Precise timestamps are a little bit slower
> > +		to obtain than jiffies-based timestamps.
> > +
> 
> Instead of "precise_timestams" will it make sense to call it
> "nanosecond_timestamps" or "ns_timestamps".
> 
> 
> >  	<program_id>
> >  	  An optional parameter.  A name that uniquely identifies
> >  	  the userspace owner of the range.  This groups ranges together
> 
> We are adding these new parameters/arguments in between existing parameters.
> Will it break any of the existing scritps. Will it make sense to add these
> new parameters at the end. It is more intuitive.

It could break someone who uses number as program_id - but there is no 
program on Linux with name that is a pure number.

We can't add it at the end because program_id and aux_data are already 
optional arguments.

> Also, I was wondering that why do we need to introduce this notion of
> number of optional arguments. Can't we just introduce another optional
> parameter [ns_timestamps]. That feels little simpler.

Then, it will clash with program_id "ns_timestamps". Device mapper uses 
this "number of optional arguments" notation at other places, so I used it 
too,

Mikulas

> Thanks
> Vivek

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

[Vivek Goyal]

On Tue, Jun 16, 2015 at 03:27:48PM -0400, Mikulas Patocka wrote:
> 
> 
> On Tue, 16 Jun 2015, Vivek Goyal wrote:
> 
> > On Tue, Jun 09, 2015 at 05:21:39PM -0400, Mikulas Patocka wrote:
> > 
> > [..]
> > >  Messages
> > >  ========
> > >  
> > > -    @stats_create <range> <step> [<program_id> [<aux_data>]]
> > > +    @stats_create <range> <step>
> > > +    		[<number_of_optional_arguments> <optional_arguments>...]
> > > +		[<program_id> [<aux_data>]]
> > >  
> > >  	Create a new region and return the region_id.
> > >  
> > > @@ -48,6 +54,17 @@ Messages
> > >  	  "/<number_of_areas>" - the range is subdivided into the specified
> > >  				 number of areas.
> > >  
> > > +	<number_of_optional_arguments>
> > > +	  The number of optional arguments
> > > +
> > > +	<optional_arguments>
> > > +	  The following optional arguments are supported
> > > +	  precise_timestamps - use precise timer with nanosecond resolution
> > > +	  	instead of the "jiffies" variable.  When this argument is
> > > +		used, the resulting times are in nanoseconds instead of
> > > +		milliseconds.  Precise timestamps are a little bit slower
> > > +		to obtain than jiffies-based timestamps.
> > > +
> > 
> > Instead of "precise_timestams" will it make sense to call it
> > "nanosecond_timestamps" or "ns_timestamps".
> > 
> > 
> > >  	<program_id>
> > >  	  An optional parameter.  A name that uniquely identifies
> > >  	  the userspace owner of the range.  This groups ranges together
> > 
> > We are adding these new parameters/arguments in between existing parameters.
> > Will it break any of the existing scritps. Will it make sense to add these
> > new parameters at the end. It is more intuitive.
> 
> It could break someone who uses number as program_id - but there is no 
> program on Linux with name that is a pure number.
> 

There does not seem to be any restriction that program_id has to be
a valid program name. It could be any string. I used a program id
of 25 and it works.

[root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_create - /1
25
0

[root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_create - /2
30
1

[root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_list 25
0: 0+585465856 585465856 25 -

[root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_list
0: 0+585465856 585465856 25 -
1: 0+585465856 292732928 30 -

May be we can introduce a new message to handle this new number of
arguments syntax. Say "stats_create_v2". That way existing programs
will not be broken, if any.


> We can't add it at the end because program_id and aux_data are already 
> optional arguments.
> 
> > Also, I was wondering that why do we need to introduce this notion of
> > number of optional arguments. Can't we just introduce another optional
> > parameter [ns_timestamps]. That feels little simpler.
> 
> Then, it will clash with program_id "ns_timestamps". Device mapper uses 
> this "number of optional arguments" notation at other places, so I used it 
> too,

BTW, I have a very stupid question. This probably stems from the fact that
I don't know enough about dm argument parsing. 

Why can't I pass the argument in same format as command line. So how
about.

@stats_create [program_id=<program_id>] [aux_data=<aux_data>]

That way we know what arguments are coming. There is no guessing and 
handling optional parameters is easy too.

Thanks
Vivek

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

[Mikulas Patocka]

On Tue, 16 Jun 2015, Vivek Goyal wrote:

> On Tue, Jun 16, 2015 at 03:27:48PM -0400, Mikulas Patocka wrote:
> > 
> > 
> > On Tue, 16 Jun 2015, Vivek Goyal wrote:
> > 
> > > On Tue, Jun 09, 2015 at 05:21:39PM -0400, Mikulas Patocka wrote:
> > > 
> > > [..]
> > > >  Messages
> > > >  ========
> > > >  
> > > > -    @stats_create <range> <step> [<program_id> [<aux_data>]]
> > > > +    @stats_create <range> <step>
> > > > +    		[<number_of_optional_arguments> <optional_arguments>...]
> > > > +		[<program_id> [<aux_data>]]
> > > >  
> > > >  	Create a new region and return the region_id.
> > > >  
> > > > @@ -48,6 +54,17 @@ Messages
> > > >  	  "/<number_of_areas>" - the range is subdivided into the specified
> > > >  				 number of areas.
> > > >  
> > > > +	<number_of_optional_arguments>
> > > > +	  The number of optional arguments
> > > > +
> > > > +	<optional_arguments>
> > > > +	  The following optional arguments are supported
> > > > +	  precise_timestamps - use precise timer with nanosecond resolution
> > > > +	  	instead of the "jiffies" variable.  When this argument is
> > > > +		used, the resulting times are in nanoseconds instead of
> > > > +		milliseconds.  Precise timestamps are a little bit slower
> > > > +		to obtain than jiffies-based timestamps.
> > > > +
> > > 
> > > Instead of "precise_timestams" will it make sense to call it
> > > "nanosecond_timestamps" or "ns_timestamps".
> > > 
> > > 
> > > >  	<program_id>
> > > >  	  An optional parameter.  A name that uniquely identifies
> > > >  	  the userspace owner of the range.  This groups ranges together
> > > 
> > > We are adding these new parameters/arguments in between existing parameters.
> > > Will it break any of the existing scritps. Will it make sense to add these
> > > new parameters at the end. It is more intuitive.
> > 
> > It could break someone who uses number as program_id - but there is no 
> > program on Linux with name that is a pure number.
> > 
> 
> There does not seem to be any restriction that program_id has to be
> a valid program name. It could be any string. I used a program id
> of 25 and it works.

The purpose of program_id is that different programs don't step over each 
other's statistics. Your program should use the program name as program_id 
to make sure that it doesn't collide.

> [root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_create - /1
> 25
> 0
> 
> [root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_create - /2
> 30
> 1
> 
> [root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_list 25
> 0: 0+585465856 585465856 25 -
> 
> [root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_list
> 0: 0+585465856 585465856 25 -
> 1: 0+585465856 292732928 30 -
> 
> May be we can introduce a new message to handle this new number of
> arguments syntax. Say "stats_create_v2". That way existing programs
> will not be broken, if any.

There are no existing programs that use numbers as program_id.

> > We can't add it at the end because program_id and aux_data are already 
> > optional arguments.
> > 
> > > Also, I was wondering that why do we need to introduce this notion of
> > > number of optional arguments. Can't we just introduce another optional
> > > parameter [ns_timestamps]. That feels little simpler.
> > 
> > Then, it will clash with program_id "ns_timestamps". Device mapper uses 
> > this "number of optional arguments" notation at other places, so I used it 
> > too,
> 
> BTW, I have a very stupid question. This probably stems from the fact that
> I don't know enough about dm argument parsing. 
> 
> Why can't I pass the argument in same format as command line. So how
> about.
> 
> @stats_create [program_id=<program_id>] [aux_data=<aux_data>]
> 
> That way we know what arguments are coming. There is no guessing and 
> handling optional parameters is easy too.

Other dm targets don't use this style of argument passing.

Mikulas

> Thanks
> Vivek
> 

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

[Vivek Goyal]

On Wed, Jun 17, 2015 at 09:17:40AM -0400, Mikulas Patocka wrote:

[..]
> > > > >  	<program_id>
> > > > >  	  An optional parameter.  A name that uniquely identifies
> > > > >  	  the userspace owner of the range.  This groups ranges together
> > > > 
> > > > We are adding these new parameters/arguments in between existing parameters.
> > > > Will it break any of the existing scritps. Will it make sense to add these
> > > > new parameters at the end. It is more intuitive.
> > > 
> > > It could break someone who uses number as program_id - but there is no 
> > > program on Linux with name that is a pure number.
> > > 
> > 
> > There does not seem to be any restriction that program_id has to be
> > a valid program name. It could be any string. I used a program id
> > of 25 and it works.
> 
> The purpose of program_id is that different programs don't step over each 
> other's statistics. Your program should use the program name as program_id 
> to make sure that it doesn't collide.

I think it would be reasonable use "pid" as program_id when different
instance of same program want to keep track of different regions of
disk.

Thanks
Vivek

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

[Bryn M. Reeves]

On Wed, Jun 17, 2015 at 09:20:33AM -0400, Vivek Goyal wrote:
> I think it would be reasonable use "pid" as program_id when different
> instance of same program want to keep track of different regions of
> disk.

Nothing stops you from doing that; just pass e.g. "mylvmstat$PID" as
the program_id.

Regards,
Bryn.

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

[Bryn M. Reeves]

On Wed, Jun 17, 2015 at 09:17:40AM -0400, Mikulas Patocka wrote:
> There are no existing programs that use numbers as program_id.

Right; even the earliest lvmstat prototypes were using "lvmstat1" for this.

Regards,
Bryn.

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

[Bryn M. Reeves]

On Tue, Jun 16, 2015 at 09:43:24PM -0400, Vivek Goyal wrote:
> There does not seem to be any restriction that program_id has to be
> a valid program name. It could be any string. I used a program id
> of 25 and it works.

That's always been the case - program_id (and aux_data) are just opaque
strings that the kernel stores for userspace.
 
> [root@tiger ~]# dmsetup message docker-docker--pool 0 @stats_create - /1
> 25
> 0

> May be we can introduce a new message to handle this new number of
> arguments syntax. Say "stats_create_v2". That way existing programs
> will not be broken, if any.

If we introduce new messages it would be good to make them extensible,
i.e. something like the form used for table constructor arguments: a
field indicating the number of arguments and arguments either describing
themselves or fitting a structure that can be expanded as needed.

> @stats_create [program_id=<program_id>] [aux_data=<aux_data>]
> 
> That way we know what arguments are coming. There is no guessing and 
> handling optional parameters is easy too.

Just that it's more string munging in the kernel. This is why e.g.
multipath's first argument is the number of feature arguments etc.

Regards,
Bryn.

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

[Bryn M. Reeves]

On Tue, Jun 09, 2015 at 05:21:39PM -0400, Mikulas Patocka wrote:
>  	/*
>  	 * Input format:
> -	 *   <range> <step> [<program_id> [<aux_data>]]
> +	 *   <range> <step> [<extra_parameters> <parameters>] [<program_id> [<aux_data>]]
>  	 */

Rather than adding optional parameters would it make sense to add a new
create method? E.g. "@stats_create_precise".

In some ways this is easier to deal with in userspace and there's alrady
a precedent for it with @stats_print vs. @stats_print_clear.

It's not a huge deal either way though - just simplifies formatting of
the messages a little.

Regards,
Bryn.

[PATCH 3/4] dm stats: report histogram of latencies

[Mikulas Patocka]

This patch adds an option to dm statistics to collect and report the
histogram of latencies.

Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>

---
 Documentation/device-mapper/statistics.txt |   21 ++-
 drivers/md/dm-stats.c                      |  201 +++++++++++++++++++++++++----
 2 files changed, 196 insertions(+), 26 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:38:43.000000000 +0200
+++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-08 17:02:01.000000000 +0200
@@ -29,6 +29,7 @@ struct dm_stat_percpu {
 	unsigned long long io_ticks[2];
 	unsigned long long io_ticks_total;
 	unsigned long long time_in_queue;
+	unsigned long long *histogram;
 };
 
 struct dm_stat_shared {
@@ -45,11 +46,14 @@ struct dm_stat {
 	sector_t start;
 	sector_t end;
 	sector_t step;
+	unsigned n_histogram_entries;
+	unsigned long long *histogram_boundaries;
 	const char *program_id;
 	const char *aux_data;
 	struct rcu_head rcu_head;
 	size_t shared_alloc_size;
 	size_t percpu_alloc_size;
+	size_t histogram_alloc_size;
 	struct dm_stat_percpu *stat_percpu[NR_CPUS];
 	struct dm_stat_shared stat_shared[0];
 };
@@ -176,8 +180,11 @@ static void dm_stat_free(struct rcu_head
 
 	kfree(s->program_id);
 	kfree(s->aux_data);
-	for_each_possible_cpu(cpu)
+	for_each_possible_cpu(cpu) {
+		dm_kvfree(s->stat_percpu[cpu][0].histogram, s->histogram_alloc_size);
 		dm_kvfree(s->stat_percpu[cpu], s->percpu_alloc_size);
+	}
+	dm_kvfree(s->stat_shared[0].tmp.histogram, s->histogram_alloc_size);
 	dm_kvfree(s, s->shared_alloc_size);
 }
 
@@ -231,6 +238,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, unsigned stat_flags,
+			   unsigned n_histogram_entries,
+			   unsigned long long *histogram_boundaries,
 			   const char *program_id, const char *aux_data,
 			   void (*suspend_callback)(struct mapped_device *),
 			   void (*resume_callback)(struct mapped_device *),
@@ -242,6 +251,7 @@ static int dm_stats_create(struct dm_sta
 	size_t ni;
 	size_t shared_alloc_size;
 	size_t percpu_alloc_size;
+	size_t histogram_alloc_size;
 	struct dm_stat_percpu *p;
 	int cpu;
 	int ret_id;
@@ -265,7 +275,11 @@ static int dm_stats_create(struct dm_sta
 	if (percpu_alloc_size / sizeof(struct dm_stat_percpu) != n_entries)
 		return -EOVERFLOW;
 
-	if (!check_shared_memory(shared_alloc_size + num_possible_cpus() * percpu_alloc_size))
+	histogram_alloc_size = (n_histogram_entries + 1) * (size_t)n_entries * sizeof(unsigned long long);
+	if (histogram_alloc_size / (n_histogram_entries + 1) != (size_t)n_entries * sizeof(unsigned long long))
+		return -EOVERFLOW;
+
+	if (!check_shared_memory(shared_alloc_size + histogram_alloc_size + num_possible_cpus() * (percpu_alloc_size + histogram_alloc_size)))
 		return -ENOMEM;
 
 	s = dm_kvzalloc(shared_alloc_size, NUMA_NO_NODE);
@@ -279,6 +293,14 @@ static int dm_stats_create(struct dm_sta
 	s->step = step;
 	s->shared_alloc_size = shared_alloc_size;
 	s->percpu_alloc_size = percpu_alloc_size;
+	s->histogram_alloc_size = histogram_alloc_size;
+
+	s->n_histogram_entries = n_histogram_entries;
+	s->histogram_boundaries = kmemdup(histogram_boundaries, s->n_histogram_entries * sizeof(unsigned long long), GFP_KERNEL);
+	if (!s->histogram_boundaries) {
+		r = -ENOMEM;
+		goto out;
+	}
 
 	s->program_id = kstrdup(program_id, GFP_KERNEL);
 	if (!s->program_id) {
@@ -296,6 +318,19 @@ static int dm_stats_create(struct dm_sta
 		atomic_set(&s->stat_shared[ni].in_flight[WRITE], 0);
 	}
 
+	if (s->n_histogram_entries) {
+		unsigned long long *hi;
+		hi = dm_kvzalloc(s->histogram_alloc_size, NUMA_NO_NODE);
+		if (!hi) {
+			r = -ENOMEM;
+			goto out;
+		}
+		for (ni = 0; ni < n_entries; ni++) {
+			s->stat_shared[ni].tmp.histogram = hi;
+			hi += s->n_histogram_entries + 1;
+		}
+	}
+
 	for_each_possible_cpu(cpu) {
 		p = dm_kvzalloc(percpu_alloc_size, cpu_to_node(cpu));
 		if (!p) {
@@ -303,6 +338,18 @@ static int dm_stats_create(struct dm_sta
 			goto out;
 		}
 		s->stat_percpu[cpu] = p;
+		if (s->n_histogram_entries) {
+			unsigned long long *hi;
+			hi = dm_kvzalloc(s->histogram_alloc_size, cpu_to_node(cpu));
+			if (!hi) {
+				r = -ENOMEM;
+				goto out;
+			}
+			for (ni = 0; ni < n_entries; ni++) {
+				p[ni].histogram = hi;
+				hi += s->n_histogram_entries + 1;
+			}
+		}
 	}
 
 	/*
@@ -380,9 +427,11 @@ static int dm_stats_delete(struct dm_sta
 	 * vfree can't be called from RCU callback
 	 */
 	for_each_possible_cpu(cpu)
-		if (is_vmalloc_addr(s->stat_percpu))
+		if (is_vmalloc_addr(s->stat_percpu) ||
+		    is_vmalloc_addr(s->stat_percpu[cpu][0].histogram))
 			goto do_sync_free;
-	if (is_vmalloc_addr(s)) {
+	if (is_vmalloc_addr(s) ||
+	    is_vmalloc_addr(s->stat_shared[0].tmp.histogram)) {
 do_sync_free:
 		synchronize_rcu_expedited();
 		dm_stat_free(&s->rcu_head);
@@ -490,15 +539,32 @@ static void dm_stat_for_entry(struct dm_
 		dm_stat_round(s, shared, p);
 		atomic_inc(&shared->in_flight[idx]);
 	} else {
+		unsigned long long duration;
 		dm_stat_round(s, shared, p);
 		atomic_dec(&shared->in_flight[idx]);
 		p->sectors[idx] += len;
 		p->ios[idx] += 1;
 		p->merges[idx] += stats_aux->merged;
-		if (!(s->stat_flags & STAT_PRECISE_TIMESTAMPS))
+		if (!(s->stat_flags & STAT_PRECISE_TIMESTAMPS)) {
 			p->ticks[idx] += duration_jiffies;
-		else
+			duration = jiffies_to_msecs(duration_jiffies);
+		} else {
 			p->ticks[idx] += stats_aux->duration_ns;
+			duration = stats_aux->duration_ns;
+		}
+		if (s->n_histogram_entries) {
+			unsigned lo = 0, hi = s->n_histogram_entries + 1;
+			while (lo + 1 < hi) {
+				unsigned mid = (lo + hi) / 2;
+				if (s->histogram_boundaries[mid - 1] > duration) {
+					hi = mid;
+				} else {
+					lo = mid;
+				}
+
+			}
+			p->histogram[lo]++;
+		}
 	}
 
 #if BITS_PER_LONG == 32
@@ -604,7 +670,22 @@ static void __dm_stat_init_temporary_per
 	dm_stat_round(s, shared, p);
 	local_irq_enable();
 
-	memset(&shared->tmp, 0, sizeof(shared->tmp));
+	shared->tmp.sectors[READ] = 0;
+	shared->tmp.sectors[WRITE] = 0;
+	shared->tmp.ios[READ] = 0;
+	shared->tmp.ios[WRITE] = 0;
+	shared->tmp.merges[READ] = 0;
+	shared->tmp.merges[WRITE] = 0;
+	shared->tmp.ticks[READ] = 0;
+	shared->tmp.ticks[WRITE] = 0;
+	shared->tmp.io_ticks[READ] = 0;
+	shared->tmp.io_ticks[WRITE] = 0;
+	shared->tmp.io_ticks_total = 0;
+	shared->tmp.time_in_queue = 0;
+
+	if (s->n_histogram_entries)
+		memset(shared->tmp.histogram, 0, (s->n_histogram_entries + 1) * sizeof(unsigned long long));
+
 	for_each_possible_cpu(cpu) {
 		p = &s->stat_percpu[cpu][x];
 		shared->tmp.sectors[READ] += ACCESS_ONCE(p->sectors[READ]);
@@ -619,6 +700,11 @@ static void __dm_stat_init_temporary_per
 		shared->tmp.io_ticks[WRITE] += ACCESS_ONCE(p->io_ticks[WRITE]);
 		shared->tmp.io_ticks_total += ACCESS_ONCE(p->io_ticks_total);
 		shared->tmp.time_in_queue += ACCESS_ONCE(p->time_in_queue);
+		if (s->n_histogram_entries) {
+			unsigned i;
+			for (i = 0; i < s->n_histogram_entries + 1; i++)
+				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
+		}
 	}
 }
 
@@ -648,6 +734,15 @@ static void __dm_stat_clear(struct dm_st
 		p->io_ticks_total -= shared->tmp.io_ticks_total;
 		p->time_in_queue -= shared->tmp.time_in_queue;
 		local_irq_enable();
+		if (s->n_histogram_entries) {
+			unsigned i;
+			for (i = 0; i < s->n_histogram_entries + 1; i++) {
+				local_irq_disable();
+				p = &s->stat_percpu[smp_processor_id()][x];
+				p->histogram[i] -= shared->tmp.histogram[i];
+				local_irq_enable();
+			}
+		}
 	}
 }
 
@@ -737,7 +832,7 @@ static int dm_stats_print(struct dm_stat
 
 		__dm_stat_init_temporary_percpu_totals(shared, s, x);
 
-		DMEMIT("%llu+%llu %llu %llu %llu %llu %llu %llu %llu %llu %d %llu %llu %llu %llu\n",
+		DMEMIT("%llu+%llu %llu %llu %llu %llu %llu %llu %llu %llu %d %llu %llu %llu %llu",
 		       (unsigned long long)start,
 		       (unsigned long long)step,
 		       shared->tmp.ios[READ],
@@ -753,6 +848,13 @@ static int dm_stats_print(struct dm_stat
 		       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 (s->n_histogram_entries) {
+			unsigned i;
+			for (i = 0; i < s->n_histogram_entries + 1; i++) {
+				DMEMIT("%s%llu", !i ? " " : ":", shared->tmp.histogram[i]);
+			}
+		}
+		DMEMIT("\n");
 
 		if (unlikely(sz + 1 >= maxlen))
 			goto buffer_overflow;
@@ -794,10 +896,46 @@ static int dm_stats_set_aux(struct dm_st
 	return 0;
 }
 
+static int parse_histogram(const char *h, unsigned *n_histogram_entries, unsigned long long **histogram_boundaries)
+{
+	const char *q;
+	unsigned n;
+	unsigned long long last;
+
+	*n_histogram_entries = 1;
+	for (q = h; *q; q++)
+		if (*q == ',')
+			(*n_histogram_entries)++;
+
+	*histogram_boundaries = kmalloc(*n_histogram_entries * sizeof(unsigned long long), GFP_KERNEL);
+	if (!*histogram_boundaries)
+		return -ENOMEM;
+
+	n = 0;
+	last = 0;
+	while (1) {
+		unsigned long long hi;
+		int s;
+		char ch;
+		s = sscanf(h, "%llu%c", &hi, &ch);
+		if (!s || (s == 2 && ch != ','))
+			return -EINVAL;
+		if (hi <= last)
+			return -EINVAL;
+		last = hi;
+		(*histogram_boundaries)[n] = hi;
+		if (s == 1)
+			return 0;
+		h = strchr(h, ',') + 1;
+		n++;
+	}
+}
+
 static int message_stats_create(struct mapped_device *md,
 				unsigned argc, char **argv,
 				char *result, unsigned maxlen)
 {
+	int r;
 	int id;
 	char dummy;
 	unsigned long long start, end, len, step;
@@ -805,6 +943,9 @@ static int message_stats_create(struct m
 	const char *program_id, *aux_data;
 	unsigned stat_flags = 0;
 
+	unsigned n_histogram_entries = 0;
+	unsigned long long *histogram_boundaries = NULL;
+
 	struct dm_arg_set as, as_backup;
 	const char *a;
 	unsigned feature_args;
@@ -815,7 +956,7 @@ static int message_stats_create(struct m
 	 */
 
 	if (argc < 3)
-		return -EINVAL;
+		goto ret_einval;
 
 	as.argc = argc;
 	as.argv = argv;
@@ -829,11 +970,11 @@ static int message_stats_create(struct m
 			len = 1;
 	} else if (sscanf(a, "%llu+%llu%c", &start, &len, &dummy) != 2 ||
 		   start != (sector_t)start || len != (sector_t)len)
-		return -EINVAL;
+		goto ret_einval;
 
 	end = start + len;
 	if (start >= end)
-		return -EINVAL;
+		goto ret_einval;
 
 	a = dm_shift_arg(&as);
 	if (sscanf(a, "/%u%c", &divisor, &dummy) == 1) {
@@ -846,7 +987,7 @@ static int message_stats_create(struct m
 			step = 1;
 	} else if (sscanf(a, "%llu%c", &step, &dummy) != 1 ||
 		   step != (sector_t)step || !step)
-		return -EINVAL;
+		goto ret_einval;
 
 	as_backup = as;
 	a = dm_shift_arg(&as);
@@ -854,11 +995,16 @@ static int message_stats_create(struct m
 		while (feature_args--) {
 			a = dm_shift_arg(&as);
 			if (!a)
-				return -EINVAL;
+				goto ret_einval;
 			if (!strcasecmp(a, "precise_timestamps"))
 				stat_flags |= STAT_PRECISE_TIMESTAMPS;
-			else
-				return -EINVAL;
+			else if (!strncasecmp(a, "histogram:", 10)) {
+				if (n_histogram_entries)
+					goto ret_einval;
+				if ((r = parse_histogram(a + 10, &n_histogram_entries, &histogram_boundaries)))
+					goto ret;
+			} else
+				goto ret_einval;
 		}
 	} else {
 		as = as_backup;
@@ -876,7 +1022,7 @@ static int message_stats_create(struct m
 		aux_data = a;
 
 	if (as.argc)
-		return -EINVAL;
+		goto ret_einval;
 
 	/*
 	 * If a buffer overflow happens after we created the region,
@@ -885,17 +1031,28 @@ static int message_stats_create(struct m
 	 * leaked).  So we must detect buffer overflow in advance.
 	 */
 	snprintf(result, maxlen, "%d", INT_MAX);
-	if (dm_message_test_buffer_overflow(result, maxlen))
-		return 1;
+	if (dm_message_test_buffer_overflow(result, maxlen)) {
+		r = 1;
+		goto ret;
+	}
 
-	id = dm_stats_create(dm_get_stats(md), start, end, step, stat_flags, program_id, aux_data,
+	id = dm_stats_create(dm_get_stats(md), start, end, step, stat_flags, n_histogram_entries, histogram_boundaries, program_id, aux_data,
 			     dm_internal_suspend_fast, dm_internal_resume_fast, md);
-	if (id < 0)
-		return id;
+	if (id < 0) {
+		r = id;
+		goto ret;
+	}
 
 	snprintf(result, maxlen, "%d", id);
 
-	return 1;
+	r = 1;
+	goto ret;
+
+ret_einval:
+	r = -EINVAL;
+ret:
+	kfree(histogram_boundaries);
+	return r;
 }
 
 static int message_stats_delete(struct mapped_device *md,
Index: linux-4.1-rc7/Documentation/device-mapper/statistics.txt
===================================================================
--- linux-4.1-rc7.orig/Documentation/device-mapper/statistics.txt	2015-06-08 17:02:11.000000000 +0200
+++ linux-4.1-rc7/Documentation/device-mapper/statistics.txt	2015-06-08 17:08:49.000000000 +0200
@@ -13,9 +13,10 @@ the range specified.
 The I/O statistics counters for each step-sized area of a region are
 in the same format as /sys/block/*/stat or /proc/diskstats (see:
 Documentation/iostats.txt).  But two extra counters (12 and 13) are
-provided: total time spent reading and writing.  All these counters may
-be accessed by sending the @stats_print message to the appropriate DM
-device via dmsetup.
+provided: total time spent reading and writing.  When the histogram
+argument is used, the 14th parameter is reported that represents the
+histogram of latencies.  All these counters may be accessed by sending
+the @stats_print message to the appropriate DM device via dmsetup.
 
 The reported times are in milliseconds and the granularity depends on
 the kernel ticks.  When the option precise_timestamps is used, the
@@ -60,10 +61,22 @@ Messages
 	<optional_arguments>
 	  The following optional arguments are supported
 	  precise_timestamps - use precise timer with nanosecond resolution
-	  	instead of the "jiffies" variable.  When this argument is
+		instead of the "jiffies" variable.  When this argument is
 		used, the resulting times are in nanoseconds instead of
 		milliseconds.  Precise timestamps are a little bit slower
 		to obtain than jiffies-based timestamps.
+	  histogram:n1,n2,n3,n4,... - collect histogram of latencies.  The
+		numbers n1, n2, etc are times that represent the boundaries
+		of the histogram.  If precise_timestamps is not used, the
+		times are in milliseconds, otherwise they are in
+		nanoseconds.  For each range, the kernel will report the
+		number of requests that completed within this range. For
+		example, if we use "histogram:10,20,30", the kernel will
+		report four numbers a:b:c:d. a is the number of requests
+		that took 0-10 ms to complete, b is the number of requests
+		that took 10-20 ms to complete, c is the number of requests
+		that took 20-30 ms to complete and d is the number of
+		requests that took more than 30 ms to complete.
 
 	<program_id>
 	  An optional parameter.  A name that uniquely identifies

Re: [PATCH 3/4] dm stats: report histogram of latencies

[Coly Li]

在 15/6/10 上午5:22, Mikulas Patocka 写道:
> This patch adds an option to dm statistics to collect and report the
> histogram of latencies.
>
> Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>
>
> ---
>  Documentation/device-mapper/statistics.txt |   21 ++-
>  drivers/md/dm-stats.c                      |  201 +++++++++++++++++++++++++----
>  2 files changed, 196 insertions(+), 26 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:38:43.000000000 +0200
> +++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-08 17:02:01.000000000 +0200
> @@ -29,6 +29,7 @@ struct dm_stat_percpu {
>  	unsigned long long io_ticks[2];
>  	unsigned long long io_ticks_total;
>  	unsigned long long time_in_queue;
> +	unsigned long long *histogram;
>  };
>  
>  struct dm_stat_shared {
[snip]
> @@ -619,6 +700,11 @@ static void __dm_stat_init_temporary_per
>  		shared->tmp.io_ticks[WRITE] += ACCESS_ONCE(p->io_ticks[WRITE]);
>  		shared->tmp.io_ticks_total += ACCESS_ONCE(p->io_ticks_total);
>  		shared->tmp.time_in_queue += ACCESS_ONCE(p->time_in_queue);
> +		if (s->n_histogram_entries) {
> +			unsigned i;
> +			for (i = 0; i < s->n_histogram_entries + 1; i++)
> +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);

s->n_histogram_entries + 1 in for() looping will be calculated many times, maybe this way could be better,

+		if (s->n_histogram_entries) {
+			unsigned i, j;
+			j = s->n_histogram_entries + 1;
+			for (i = 0; i < j; i++)
+				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);

> +		}
>  	}
>  }
>  
> @@ -648,6 +734,15 @@ static void __dm_stat_clear(struct dm_st
>  		p->io_ticks_total -= shared->tmp.io_ticks_total;
>  		p->time_in_queue -= shared->tmp.time_in_queue;
>  		local_irq_enable();
> +		if (s->n_histogram_entries) {
> +			unsigned i;
> +			for (i = 0; i < s->n_histogram_entries + 1; i++) {
Same situation here,

+            unsigned i, j;
+            j = s->n_histogram_entries + 1;
+            for (i = 0; i < j; i++) {

> +				local_irq_disable();
> +				p = &s->stat_percpu[smp_processor_id()][x];
> +				p->histogram[i] -= shared->tmp.histogram[i];
> +				local_irq_enable();
> +			}
> +		}
>  	}
>  }
>  
> @@ -737,7 +832,7 @@ static int dm_stats_print(struct dm_stat
>  
>  		__dm_stat_init_temporary_percpu_totals(shared, s, x);
>  
> -		DMEMIT("%llu+%llu %llu %llu %llu %llu %llu %llu %llu %llu %d %llu %llu %llu %llu\n",
> +		DMEMIT("%llu+%llu %llu %llu %llu %llu %llu %llu %llu %llu %d %llu %llu %llu %llu",
>  		       (unsigned long long)start,
>  		       (unsigned long long)step,
>  		       shared->tmp.ios[READ],
> @@ -753,6 +848,13 @@ static int dm_stats_print(struct dm_stat
>  		       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 (s->n_histogram_entries) {
> +			unsigned i;
> +			for (i = 0; i < s->n_histogram_entries + 1; i++) {
Same situation here,

+                        unsigned i, j;
+                        j = s->n_histogram_entries + 1;
+                        for (i = 0; i < j; i++) {

> +				DMEMIT("%s%llu", !i ? " " : ":", shared->tmp.histogram[i]);
> +			}
> +		}
> +		DMEMIT("\n");
>  
>  		if (unlikely(sz + 1 >= maxlen))
>  			goto buffer_overflow;
[snip]

Coly

--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

Re: [PATCH 3/4] dm stats: report histogram of latencies

[Mikulas Patocka]

These micro optimizations would save one or two instructions, so they are 
not really needed. Also, these micro optimizations are at a code path that 
prints the statistics, not the code path that processes i/o requests.

Mikulas


On Sun, 14 Jun 2015, Coly Li wrote:

> ? 15/6/10 ??5:22, Mikulas Patocka ??:
> > This patch adds an option to dm statistics to collect and report the
> > histogram of latencies.
> >
> > Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>
> >
> > ---
> >  Documentation/device-mapper/statistics.txt |   21 ++-
> >  drivers/md/dm-stats.c                      |  201 +++++++++++++++++++++++++----
> >  2 files changed, 196 insertions(+), 26 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:38:43.000000000 +0200
> > +++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-08 17:02:01.000000000 +0200
> > @@ -29,6 +29,7 @@ struct dm_stat_percpu {
> >  	unsigned long long io_ticks[2];
> >  	unsigned long long io_ticks_total;
> >  	unsigned long long time_in_queue;
> > +	unsigned long long *histogram;
> >  };
> >  
> >  struct dm_stat_shared {
> [snip]
> > @@ -619,6 +700,11 @@ static void __dm_stat_init_temporary_per
> >  		shared->tmp.io_ticks[WRITE] += ACCESS_ONCE(p->io_ticks[WRITE]);
> >  		shared->tmp.io_ticks_total += ACCESS_ONCE(p->io_ticks_total);
> >  		shared->tmp.time_in_queue += ACCESS_ONCE(p->time_in_queue);
> > +		if (s->n_histogram_entries) {
> > +			unsigned i;
> > +			for (i = 0; i < s->n_histogram_entries + 1; i++)
> > +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
> 
> s->n_histogram_entries + 1 in for() looping will be calculated many times, maybe this way could be better,
> 
> +		if (s->n_histogram_entries) {
> +			unsigned i, j;
> +			j = s->n_histogram_entries + 1;
> +			for (i = 0; i < j; i++)
> +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
> 
> > +		}
> >  	}
> >  }
> >  
> > @@ -648,6 +734,15 @@ static void __dm_stat_clear(struct dm_st
> >  		p->io_ticks_total -= shared->tmp.io_ticks_total;
> >  		p->time_in_queue -= shared->tmp.time_in_queue;
> >  		local_irq_enable();
> > +		if (s->n_histogram_entries) {
> > +			unsigned i;
> > +			for (i = 0; i < s->n_histogram_entries + 1; i++) {
> Same situation here,
> 
> +            unsigned i, j;
> +            j = s->n_histogram_entries + 1;
> +            for (i = 0; i < j; i++) {
> 
> > +				local_irq_disable();
> > +				p = &s->stat_percpu[smp_processor_id()][x];
> > +				p->histogram[i] -= shared->tmp.histogram[i];
> > +				local_irq_enable();
> > +			}
> > +		}
> >  	}
> >  }
> >  
> > @@ -737,7 +832,7 @@ static int dm_stats_print(struct dm_stat
> >  
> >  		__dm_stat_init_temporary_percpu_totals(shared, s, x);
> >  
> > -		DMEMIT("%llu+%llu %llu %llu %llu %llu %llu %llu %llu %llu %d %llu %llu %llu %llu\n",
> > +		DMEMIT("%llu+%llu %llu %llu %llu %llu %llu %llu %llu %llu %d %llu %llu %llu %llu",
> >  		       (unsigned long long)start,
> >  		       (unsigned long long)step,
> >  		       shared->tmp.ios[READ],
> > @@ -753,6 +848,13 @@ static int dm_stats_print(struct dm_stat
> >  		       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 (s->n_histogram_entries) {
> > +			unsigned i;
> > +			for (i = 0; i < s->n_histogram_entries + 1; i++) {
> Same situation here,
> 
> +                        unsigned i, j;
> +                        j = s->n_histogram_entries + 1;
> +                        for (i = 0; i < j; i++) {
> 
> > +				DMEMIT("%s%llu", !i ? " " : ":", shared->tmp.histogram[i]);
> > +			}
> > +		}
> > +		DMEMIT("\n");
> >  
> >  		if (unlikely(sz + 1 >= maxlen))
> >  			goto buffer_overflow;
> [snip]
> 
> Coly
> 

Re: [PATCH 3/4] dm stats: report histogram of latencies

[Coly Li]

在 15/6/15 下午9:06, Mikulas Patocka 写道:
> These micro optimizations would save one or two instructions, so they are 
> not really needed. Also, these micro optimizations are at a code path that 
> prints the statistics, not the code path that processes i/o requests.
It is not one or two instructions, it depends on how big
s->n_histogram_entries is.
Yes I agree, it is not on critical I/O path :-)

Coly
> On Sun, 14 Jun 2015, Coly Li wrote:
>
>> ? 15/6/10 ??5:22, Mikulas Patocka ??:
>>> This patch adds an option to dm statistics to collect and report the
>>> histogram of latencies.
>>>
>>> Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>
>>>
>>> ---
>>>  Documentation/device-mapper/statistics.txt |   21 ++-
>>>  drivers/md/dm-stats.c                      |  201 +++++++++++++++++++++++++----
>>>  2 files changed, 196 insertions(+), 26 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:38:43.000000000 +0200
>>> +++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-08 17:02:01.000000000 +0200
>>> @@ -29,6 +29,7 @@ struct dm_stat_percpu {
>>>  	unsigned long long io_ticks[2];
>>>  	unsigned long long io_ticks_total;
>>>  	unsigned long long time_in_queue;
>>> +	unsigned long long *histogram;
>>>  };
>>>  
>>>  struct dm_stat_shared {
>> [snip]
>>> @@ -619,6 +700,11 @@ static void __dm_stat_init_temporary_per
>>>  		shared->tmp.io_ticks[WRITE] += ACCESS_ONCE(p->io_ticks[WRITE]);
>>>  		shared->tmp.io_ticks_total += ACCESS_ONCE(p->io_ticks_total);
>>>  		shared->tmp.time_in_queue += ACCESS_ONCE(p->time_in_queue);
>>> +		if (s->n_histogram_entries) {
>>> +			unsigned i;
>>> +			for (i = 0; i < s->n_histogram_entries + 1; i++)
>>> +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
>> s->n_histogram_entries + 1 in for() looping will be calculated many times, maybe this way could be better,
>>
>> +		if (s->n_histogram_entries) {
>> +			unsigned i, j;
>> +			j = s->n_histogram_entries + 1;
>> +			for (i = 0; i < j; i++)
>> +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
>>
>>
[snip]

--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

Re: [PATCH 3/4] dm stats: report histogram of latencies

[Mikulas Patocka]

On Mon, 15 Jun 2015, Coly Li wrote:

> ? 15/6/15 ??9:06, Mikulas Patocka ??:
> > These micro optimizations would save one or two instructions, so they are 
> > not really needed. Also, these micro optimizations are at a code path that 
> > prints the statistics, not the code path that processes i/o requests.
> It is not one or two instructions, it depends on how big
> s->n_histogram_entries is.

No, it doesn't depend on the s->n_histogram_entries.

When evaluating the expression "s->n_histogram_entries + 1", there is one 
instruction that loads s->n_histogram_entries and another instruction that 
adds 1 to it. If you replace it with pre-computed value, you save just 
those two instructions, nothing else.

Mikulas

> Yes I agree, it is not on critical I/O path :-)
> 
> Coly
> > On Sun, 14 Jun 2015, Coly Li wrote:
> >
> >> ? 15/6/10 ??5:22, Mikulas Patocka ??:
> >>> This patch adds an option to dm statistics to collect and report the
> >>> histogram of latencies.
> >>>
> >>> Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>
> >>>
> >>> ---
> >>>  Documentation/device-mapper/statistics.txt |   21 ++-
> >>>  drivers/md/dm-stats.c                      |  201 +++++++++++++++++++++++++----
> >>>  2 files changed, 196 insertions(+), 26 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:38:43.000000000 +0200
> >>> +++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-08 17:02:01.000000000 +0200
> >>> @@ -29,6 +29,7 @@ struct dm_stat_percpu {
> >>>  	unsigned long long io_ticks[2];
> >>>  	unsigned long long io_ticks_total;
> >>>  	unsigned long long time_in_queue;
> >>> +	unsigned long long *histogram;
> >>>  };
> >>>  
> >>>  struct dm_stat_shared {
> >> [snip]
> >>> @@ -619,6 +700,11 @@ static void __dm_stat_init_temporary_per
> >>>  		shared->tmp.io_ticks[WRITE] += ACCESS_ONCE(p->io_ticks[WRITE]);
> >>>  		shared->tmp.io_ticks_total += ACCESS_ONCE(p->io_ticks_total);
> >>>  		shared->tmp.time_in_queue += ACCESS_ONCE(p->time_in_queue);
> >>> +		if (s->n_histogram_entries) {
> >>> +			unsigned i;
> >>> +			for (i = 0; i < s->n_histogram_entries + 1; i++)
> >>> +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
> >> s->n_histogram_entries + 1 in for() looping will be calculated many times, maybe this way could be better,
> >>
> >> +		if (s->n_histogram_entries) {
> >> +			unsigned i, j;
> >> +			j = s->n_histogram_entries + 1;
> >> +			for (i = 0; i < j; i++)
> >> +				shared->tmp.histogram[i] += ACCESS_ONCE(p->histogram[i]);
> >>
> >>
> [snip]
> 

Re: [PATCH 3/4] dm stats: report histogram of latencies

[Vivek Goyal]

On Tue, Jun 09, 2015 at 05:22:05PM -0400, Mikulas Patocka wrote:
> This patch adds an option to dm statistics to collect and report the
> histogram of latencies.
> 
> Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>

I am wondering how does histogram help. IOW, if disks are bad, will
average latencies not go up as well and that one can already calcualte
using existing stats.

Thanks
Vivek

[PATCH 4/4] dm stats: support statistics on requests-based devices

[Mikulas Patocka]

This patch makes it possible to use dm stats on multipath.

Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>

---
 drivers/md/dm-stats.c |    5 -----
 drivers/md/dm.c       |   27 +++++++++++++++++++++++++++
 2 files changed, 27 insertions(+), 5 deletions(-)

Index: linux-4.1-rc7/drivers/md/dm-stats.c
===================================================================
--- linux-4.1-rc7.orig/drivers/md/dm-stats.c	2015-06-09 13:53:26.000000000 +0200
+++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-09 13:53:35.000000000 +0200
@@ -1155,11 +1155,6 @@ int dm_stats_message(struct mapped_devic
 {
 	int r;
 
-	if (dm_request_based(md)) {
-		DMWARN("Statistics are only supported for bio-based devices");
-		return -EOPNOTSUPP;
-	}
-
 	/* All messages here must start with '@' */
 	if (!strcasecmp(argv[0], "@stats_create"))
 		r = message_stats_create(md, argc, argv, result, maxlen);
Index: linux-4.1-rc7/drivers/md/dm.c
===================================================================
--- linux-4.1-rc7.orig/drivers/md/dm.c	2015-06-09 13:53:50.000000000 +0200
+++ linux-4.1-rc7/drivers/md/dm.c	2015-06-09 16:07:35.000000000 +0200
@@ -86,6 +86,9 @@ struct dm_rq_target_io {
 	struct kthread_work work;
 	int error;
 	union map_info info;
+	struct dm_stats_aux stats_aux;
+	unsigned long duration_jiffies;
+	unsigned n_sectors;
 };
 
 /*
@@ -1084,6 +1087,17 @@ static struct dm_rq_target_io *tio_from_
 	return (rq->q->mq_ops ? blk_mq_rq_to_pdu(rq) : rq->special);
 }
 
+static void rq_end_stats(struct mapped_device *md, struct request *orig)
+{
+	if (unlikely(dm_stats_used(&md->stats))) {
+		struct dm_rq_target_io *tio = tio_from_request(orig);
+		tio->duration_jiffies = jiffies - tio->duration_jiffies;
+		dm_stats_account_io(&md->stats, orig->cmd_flags, blk_rq_pos(orig),
+				    tio->n_sectors, true, tio->duration_jiffies,
+				    &tio->stats_aux);
+	}
+}
+
 /*
  * Don't touch any member of the md after calling this function because
  * the md may be freed in dm_put() at the end of this function.
@@ -1169,6 +1183,7 @@ static void dm_end_request(struct reques
 	}
 
 	free_rq_clone(clone);
+	rq_end_stats(md, rq);
 	if (!rq->q->mq_ops)
 		blk_end_request_all(rq, error);
 	else
@@ -1211,6 +1226,7 @@ static void dm_requeue_unmapped_original
 
 	dm_unprep_request(rq);
 
+	rq_end_stats(md, rq);
 	if (!rq->q->mq_ops)
 		old_requeue_request(rq);
 	else {
@@ -1309,6 +1325,7 @@ static void dm_softirq_done(struct reque
 	int rw;
 
 	if (!clone) {
+		rq_end_stats(tio->md, rq);
 		rw = rq_data_dir(rq);
 		if (!rq->q->mq_ops) {
 			blk_end_request_all(rq, tio->error);
@@ -2120,6 +2137,15 @@ static void dm_start_request(struct mapp
 		md->last_rq_start_time = ktime_get();
 	}
 
+	if (unlikely(dm_stats_used(&md->stats))) {
+		struct dm_rq_target_io *tio = tio_from_request(orig);
+		tio->duration_jiffies = jiffies;
+		tio->n_sectors = blk_rq_sectors(orig);
+		dm_stats_account_io(&md->stats, orig->cmd_flags, blk_rq_pos(orig),
+				    tio->n_sectors, false, 0,
+				    &tio->stats_aux);
+	}
+
 	/*
 	 * Hold the md reference here for the in-flight I/O.
 	 * We can't rely on the reference count by device opener,
@@ -2853,6 +2879,7 @@ static int dm_mq_queue_rq(struct blk_mq_
 		/* Direct call is fine since .queue_rq allows allocations */
 		if (map_request(tio, rq, md) == DM_MAPIO_REQUEUE) {
 			/* Undo dm_start_request() before requeuing */
+			rq_end_stats(md, rq);
 			rq_completed(md, rq_data_dir(rq), false);
 			return BLK_MQ_RQ_QUEUE_BUSY;
 		}

Re: [PATCH 4/4] dm stats: support statistics on requests-based devices

[Laurence Oberman]

Awesome.
Thanks I will pull the patches build and test.

Regards
Laurence

Laurence Oberman
Red Hat Global Support Service
SEG Team

----- Original Message -----
From: "Mikulas Patocka" <mpatocka@redhat.com>
To: "Alasdair G. Kergon" <agk@redhat.com>, "Mike Snitzer" <msnitzer@redhat.com>, "Coly Li" <colyli@gmail.com>
Cc: dm-devel@redhat.com, "Tao Ma" <boyu.mt@taobao.com>, "Robin Dong" <sanbai@alibaba-inc.com>, "Laurence Oberman" <loberman@redhat.com>
Sent: Tuesday, June 9, 2015 5:22:49 PM
Subject: [PATCH 4/4] dm stats: support statistics on requests-based devices

This patch makes it possible to use dm stats on multipath.

Signed-off-by: Mikulas Patocka <mpatocka@redhat.com>

---
 drivers/md/dm-stats.c |    5 -----
 drivers/md/dm.c       |   27 +++++++++++++++++++++++++++
 2 files changed, 27 insertions(+), 5 deletions(-)

Index: linux-4.1-rc7/drivers/md/dm-stats.c
===================================================================
--- linux-4.1-rc7.orig/drivers/md/dm-stats.c	2015-06-09 13:53:26.000000000 +0200
+++ linux-4.1-rc7/drivers/md/dm-stats.c	2015-06-09 13:53:35.000000000 +0200
@@ -1155,11 +1155,6 @@ int dm_stats_message(struct mapped_devic
 {
 	int r;
 
-	if (dm_request_based(md)) {
-		DMWARN("Statistics are only supported for bio-based devices");
-		return -EOPNOTSUPP;
-	}
-
 	/* All messages here must start with '@' */
 	if (!strcasecmp(argv[0], "@stats_create"))
 		r = message_stats_create(md, argc, argv, result, maxlen);
Index: linux-4.1-rc7/drivers/md/dm.c
===================================================================
--- linux-4.1-rc7.orig/drivers/md/dm.c	2015-06-09 13:53:50.000000000 +0200
+++ linux-4.1-rc7/drivers/md/dm.c	2015-06-09 16:07:35.000000000 +0200
@@ -86,6 +86,9 @@ struct dm_rq_target_io {
 	struct kthread_work work;
 	int error;
 	union map_info info;
+	struct dm_stats_aux stats_aux;
+	unsigned long duration_jiffies;
+	unsigned n_sectors;
 };
 
 /*
@@ -1084,6 +1087,17 @@ static struct dm_rq_target_io *tio_from_
 	return (rq->q->mq_ops ? blk_mq_rq_to_pdu(rq) : rq->special);
 }
 
+static void rq_end_stats(struct mapped_device *md, struct request *orig)
+{
+	if (unlikely(dm_stats_used(&md->stats))) {
+		struct dm_rq_target_io *tio = tio_from_request(orig);
+		tio->duration_jiffies = jiffies - tio->duration_jiffies;
+		dm_stats_account_io(&md->stats, orig->cmd_flags, blk_rq_pos(orig),
+				    tio->n_sectors, true, tio->duration_jiffies,
+				    &tio->stats_aux);
+	}
+}
+
 /*
  * Don't touch any member of the md after calling this function because
  * the md may be freed in dm_put() at the end of this function.
@@ -1169,6 +1183,7 @@ static void dm_end_request(struct reques
 	}
 
 	free_rq_clone(clone);
+	rq_end_stats(md, rq);
 	if (!rq->q->mq_ops)
 		blk_end_request_all(rq, error);
 	else
@@ -1211,6 +1226,7 @@ static void dm_requeue_unmapped_original
 
 	dm_unprep_request(rq);
 
+	rq_end_stats(md, rq);
 	if (!rq->q->mq_ops)
 		old_requeue_request(rq);
 	else {
@@ -1309,6 +1325,7 @@ static void dm_softirq_done(struct reque
 	int rw;
 
 	if (!clone) {
+		rq_end_stats(tio->md, rq);
 		rw = rq_data_dir(rq);
 		if (!rq->q->mq_ops) {
 			blk_end_request_all(rq, tio->error);
@@ -2120,6 +2137,15 @@ static void dm_start_request(struct mapp
 		md->last_rq_start_time = ktime_get();
 	}
 
+	if (unlikely(dm_stats_used(&md->stats))) {
+		struct dm_rq_target_io *tio = tio_from_request(orig);
+		tio->duration_jiffies = jiffies;
+		tio->n_sectors = blk_rq_sectors(orig);
+		dm_stats_account_io(&md->stats, orig->cmd_flags, blk_rq_pos(orig),
+				    tio->n_sectors, false, 0,
+				    &tio->stats_aux);
+	}
+
 	/*
 	 * Hold the md reference here for the in-flight I/O.
 	 * We can't rely on the reference count by device opener,
@@ -2853,6 +2879,7 @@ static int dm_mq_queue_rq(struct blk_mq_
 		/* Direct call is fine since .queue_rq allows allocations */
 		if (map_request(tio, rq, md) == DM_MAPIO_REQUEUE) {
 			/* Undo dm_start_request() before requeuing */
+			rq_end_stats(md, rq);
 			rq_completed(md, rq_data_dir(rq), false);
 			return BLK_MQ_RQ_QUEUE_BUSY;
 		}

Re: [PATCH 0/4] Integrate dm-latency functionality to dm-statistics

[Coly Li]

在 15/6/10 上午5:20, Mikulas Patocka 写道:
> Hi
>
> Here I'm sending patches that add funcionality provided by dm-latency into 
> dm-statistics framework. Dm-latency was introduced in this post 
> https://www.redhat.com/archives/dm-devel/2015-February/msg00158.html , 
> however, there is already similar framework dm-statistics in the kernel. 
> In order to have cleaner and easier to maintain code, it is better to 
> integrate dm-latency functionality into dm-statistics, rather than having 
> two frameworks that do similar things.
>
> This patch series makes these changes:
> * it is possible to use precise time measurement with nanosecond 
>   granularity (previously, time was measured in jiffies)
> * it is possible to collect histogram of latencies. The histogram 
>   boundaries may be selected by the user and there is unlimited number of 
>   possible boundaries (in dm-latency, the histogram boundaries were fixed)
> * it is possible to use dm-statistics on multipath
>
> The documentation of these extensions is in 
> Documentation/device-mapper/statistics.txt
>
> I'd like to ask people who designed dm-latency to check this patchset, try 
> to use it and tell us if it provides sufficient functionality to them (the 
> indended functinality of dm-latency was to predict hard disk failures from 
> i/o request latency histogram).
>

Hi Mikulas,

I was in travel last week, sorry for late response. Here are some
comments from me, just for your information,

1, If I understand correctly, latency histogram boundaries are organized by list in your implementation, and the list is searched in linear order. We had a similar but a little bit simple implementation, with very high I/O request work load on multiple hard disks, we observed 1% CPU performance cost. This is why dm-latency uses a very simple static array of counters to record I/O latency. I suggest you should do some benchmarks to compare the performance cost.

2, There should be a maximum latency histogram boundaries limitation. Maybe you do it in the patch and I missed it, that's should be my fault.

3, in message_stats_create() I see more code  to handle arguments checking. hmm, I don't check this cold block very carefully, but I suggest that string checking in kernel space should be very careful, if you may simplify current designment and remove the code for arguments checking, it might be better.

4, there are some minor suggestions, I will add my comments in other emails.

For rest of the patch set, they are good to me. Thanks for your effort to make a good start :-)

Coly

--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

Re: [PATCH 0/4] Integrate dm-latency functionality to dm-statistics

[Mikulas Patocka]

On Sun, 14 Jun 2015, Coly Li wrote:

> ? 15/6/10 ??5:20, Mikulas Patocka ??:
> > Hi
> >
> > Here I'm sending patches that add funcionality provided by dm-latency into 
> > dm-statistics framework. Dm-latency was introduced in this post 
> > https://www.redhat.com/archives/dm-devel/2015-February/msg00158.html , 
> > however, there is already similar framework dm-statistics in the kernel. 
> > In order to have cleaner and easier to maintain code, it is better to 
> > integrate dm-latency functionality into dm-statistics, rather than having 
> > two frameworks that do similar things.
> >
> > This patch series makes these changes:
> > * it is possible to use precise time measurement with nanosecond 
> >   granularity (previously, time was measured in jiffies)
> > * it is possible to collect histogram of latencies. The histogram 
> >   boundaries may be selected by the user and there is unlimited number of 
> >   possible boundaries (in dm-latency, the histogram boundaries were fixed)
> > * it is possible to use dm-statistics on multipath
> >
> > The documentation of these extensions is in 
> > Documentation/device-mapper/statistics.txt
> >
> > I'd like to ask people who designed dm-latency to check this patchset, try 
> > to use it and tell us if it provides sufficient functionality to them (the 
> > indended functinality of dm-latency was to predict hard disk failures from 
> > i/o request latency histogram).
> >
> 
> Hi Mikulas,
> 
> I was in travel last week, sorry for late response. Here are some
> comments from me, just for your information,
> 
> 1, If I understand correctly, latency histogram boundaries are organized 
> by list in your implementation, and the list is searched in linear 
> order. We had a similar but a little bit simple implementation, with 
> very high I/O request work load on multiple hard disks, we observed 1% 
> CPU performance cost. This is why dm-latency uses a very simple static 
> array of counters to record I/O latency. I suggest you should do some 
> benchmarks to compare the performance cost.

It is searched using binary search - so the complexity is logarithmic.

> 2, There should be a maximum latency histogram boundaries limitation. 
> Maybe you do it in the patch and I missed it, that's should be my fault.

There is no maximum - and there doesn't need to be any maximum because the 
array is allocated dynamically.

> 3, in message_stats_create() I see more code to handle arguments 
> checking. hmm, I don't check this cold block very carefully, but I 
> suggest that string checking in kernel space should be very careful, if 
> you may simplify current designment and remove the code for arguments 
> checking, it might be better.

I don't know why should I remove the code for arguments checking. We check 
arguments in the kernel, even if the function may be only called by root - 
to prevent bugs in userspace tools from causing kernel crash.

> 4, there are some minor suggestions, I will add my comments in other 
> emails.
> 
> For rest of the patch set, they are good to me. Thanks for your effort 
> to make a good start :-)
> 
> Coly

Mikulas

Re: [PATCH 0/4] Integrate dm-latency functionality to dm-statistics

[Coly Li]

在 15/6/15 下午8:47, Mikulas Patocka 写道:
>
> On Sun, 14 Jun 2015, Coly Li wrote:
>
>> ? 15/6/10 ??5:20, Mikulas Patocka ??:
>>> Hi
>>>
>>> Here I'm sending patches that add funcionality provided by dm-latency into 
>>> dm-statistics framework. Dm-latency was introduced in this post 
>>> https://www.redhat.com/archives/dm-devel/2015-February/msg00158.html , 
>>> however, there is already similar framework dm-statistics in the kernel. 
>>> In order to have cleaner and easier to maintain code, it is better to 
>>> integrate dm-latency functionality into dm-statistics, rather than having 
>>> two frameworks that do similar things.
>>>
>>> This patch series makes these changes:
>>> * it is possible to use precise time measurement with nanosecond 
>>>   granularity (previously, time was measured in jiffies)
>>> * it is possible to collect histogram of latencies. The histogram 
>>>   boundaries may be selected by the user and there is unlimited number of 
>>>   possible boundaries (in dm-latency, the histogram boundaries were fixed)
>>> * it is possible to use dm-statistics on multipath
>>>
>>> The documentation of these extensions is in 
>>> Documentation/device-mapper/statistics.txt
>>>
>>> I'd like to ask people who designed dm-latency to check this patchset, try 
>>> to use it and tell us if it provides sufficient functionality to them (the 
>>> indended functinality of dm-latency was to predict hard disk failures from 
>>> i/o request latency histogram).
>>>
>> Hi Mikulas,
>>
>> I was in travel last week, sorry for late response. Here are some
>> comments from me, just for your information,
>>
>> 1, If I understand correctly, latency histogram boundaries are organized 
>> by list in your implementation, and the list is searched in linear 
>> order. We had a similar but a little bit simple implementation, with 
>> very high I/O request work load on multiple hard disks, we observed 1% 
>> CPU performance cost. This is why dm-latency uses a very simple static 
>> array of counters to record I/O latency. I suggest you should do some 
>> benchmarks to compare the performance cost.
> It is searched using binary search - so the complexity is logarithmic.
It seems I didn't understand dm stats code very well, I need more time
to read and understand your patches :-)

I will test the patches in our storage product environment for the
performance number, hope it is good.
>
>> 2, There should be a maximum latency histogram boundaries limitation. 
>> Maybe you do it in the patch and I missed it, that's should be my fault.
> There is no maximum - and there doesn't need to be any maximum because the 
> array is allocated dynamically.
Maybe I am too paranoid, IMHO dynamically allocated object should have a
maximum limitation, in case of it occupies too much system resource (e.g
memory here).

>
>> 3, in message_stats_create() I see more code to handle arguments 
>> checking. hmm, I don't check this cold block very carefully, but I 
>> suggest that string checking in kernel space should be very careful, if 
>> you may simplify current designment and remove the code for arguments 
>> checking, it might be better.
> I don't know why should I remove the code for arguments checking. We check 
> arguments in the kernel, even if the function may be only called by root - 
> to prevent bugs in userspace tools from causing kernel crash.
>
I didn't express myself well. I meant to minimize the number of
parameters, so most of the arguments checking code could be removed.
I didn't mean not checking the arguments, I meant that it could be
better if much less parameters sent from user space.

Coly


--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

Re: [PATCH 0/4] Integrate dm-latency functionality to dm-statistics

[Mikulas Patocka]

On Mon, 15 Jun 2015, Coly Li wrote:

> >> 2, There should be a maximum latency histogram boundaries limitation. 
> >> Maybe you do it in the patch and I missed it, that's should be my fault.
> > There is no maximum - and there doesn't need to be any maximum because the 
> > array is allocated dynamically.
> Maybe I am too paranoid, IMHO dynamically allocated object should have a
> maximum limitation, in case of it occupies too much system resource (e.g
> memory here).

There is already that limitation of 1/4 total physical memory.

Mikulas