stats: Add a function to report completion latency percentiles
[fio.git] / stat.c
diff --git a/stat.c b/stat.c
index 326b1f763460827f05334fda03453ea39d398f27..25dd1791767437ad75de4b405b63d37debb487b6 100644 (file)
--- a/stat.c
+++ b/stat.c
@@ -28,6 +28,134 @@ void update_rusage_stat(struct thread_data *td)
        memcpy(&ts->ru_start, &ts->ru_end, sizeof(ts->ru_end));
 }
 
+/*
+ * Given a latency, return the index of the corresponding bucket in
+ * the structure tracking percentiles.
+ *
+ * (1) find the group (and error bits) that the value (latency)
+ * belongs to by looking at its MSB. (2) find the bucket number in the
+ * group by looking at the index bits.
+ *
+ */
+static unsigned int plat_val_to_idx(unsigned int val)
+{
+       unsigned int msb, error_bits, base, offset, idx;
+
+       /* Find MSB starting from bit 0 */
+       if (val == 0)
+               msb = 0;
+       else
+               msb = (sizeof(val)*8) - __builtin_clz(val) - 1;
+
+       /* MSB <= (FIO_IO_U_PLAT_BITS-1), cannot be rounded off. Use
+        * all bits of the sample as index */
+       if (msb <= FIO_IO_U_PLAT_BITS)
+               return val;
+
+       /* Compute the number of error bits to discard*/
+       error_bits = msb - FIO_IO_U_PLAT_BITS;
+
+       /* Compute the number of buckets before the group */
+       base = (error_bits + 1) << FIO_IO_U_PLAT_BITS;
+
+       /* Discard the error bits and apply the mask to find the
+         * index for the buckets in the group */
+       offset = (FIO_IO_U_PLAT_VAL - 1) & (val >> error_bits);
+
+       /* Make sure the index does not exceed (array size - 1) */
+       idx = (base + offset) < (FIO_IO_U_PLAT_NR - 1)?
+               (base + offset) : (FIO_IO_U_PLAT_NR - 1);
+
+       return idx;
+}
+
+/*
+ * Convert the given index of the bucket array to the value
+ * represented by the bucket
+ */
+static unsigned int plat_idx_to_val(unsigned int idx)
+{
+       unsigned int error_bits, k, base;
+
+       assert(idx < FIO_IO_U_PLAT_NR);
+
+       /* MSB <= (FIO_IO_U_PLAT_BITS-1), cannot be rounded off. Use
+        * all bits of the sample as index */
+       if (idx < (FIO_IO_U_PLAT_VAL << 1) )
+               return idx;
+
+       /* Find the group and compute the minimum value of that group */
+       error_bits = (idx >> FIO_IO_U_PLAT_BITS) -1;
+       base = 1 << (error_bits + FIO_IO_U_PLAT_BITS);
+
+       /* Find its bucket number of the group */
+       k = idx % FIO_IO_U_PLAT_VAL;
+
+       /* Return the mean of the range of the bucket */
+       return base + ((k + 0.5) * (1 << error_bits));
+}
+
+static int double_cmp(const void *a, const void *b)
+{
+       const double fa = *(const double *)a;
+       const double fb = *(const double *)b;
+       int cmp = 0;
+
+       if (fa > fb)
+               cmp = 1;
+       else if (fa < fb)
+               cmp = -1;
+
+       return cmp;
+}
+
+/*
+ * Find and display the p-th percentile of clat
+ */
+static void show_clat_percentiles(unsigned int* io_u_plat, unsigned long nr,
+                                double* user_list)
+{
+       unsigned long sum = 0;
+       unsigned int len, i, j = 0;
+       static const double def_list[FIO_IO_U_LIST_MAX_LEN] = {
+                       1.0, 5.0, 10.0, 20.0, 30.0,
+                       40.0, 50.0, 60.0, 70.0, 80.0,
+                       90.0, 95.0, 99.0, 99.5, 99.9};
+
+       const double* plist = user_list? user_list: def_list;
+       for (len = 0; len <FIO_IO_U_LIST_MAX_LEN && plist[len] != 0; len++) {}
+
+       /* Sort the user-specified list. Note that this does not work
+          for NaN values */
+       if (user_list && len > 1)
+               qsort((void*)user_list, len, sizeof(user_list[0]), double_cmp);
+
+       int is_last = 0;
+       log_info("    clat percentiles (usec) :");
+
+       for (i = 0; i <FIO_IO_U_PLAT_NR && !is_last; i++) {
+               sum += io_u_plat[i];
+               while (sum >= (plist[j]/100 * nr)) {
+                       assert(plist[j] <= 100.0);
+
+                       if (j!=0 && (j%4) == 0) /* for formatting */
+                               log_info("                             ");
+
+                       /* end of the list */
+                       is_last = (j == len - 1);
+
+                       log_info(" %2.2fth=%u%c", plist[j], plat_idx_to_val(i),
+                                (is_last? '\n' : ','));
+
+                       if (is_last) break;
+
+                       if (j%4 == 3)   /* for formatting */
+                               log_info("\n");
+                       j++;
+               }
+       }
+}
+
 static int calc_lat(struct io_stat *is, unsigned long *min, unsigned long *max,
                    double *mean, double *dev)
 {
@@ -169,10 +297,10 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
        io_p = num2str(ts->io_bytes[ddir], 6, 1, i2p);
        bw_p = num2str(bw, 6, 1, i2p);
 
-       iops = (1000 * ts->total_io_u[ddir]) / runt;
+       iops = (1000 * (uint64_t)ts->total_io_u[ddir]) / runt;
        iops_p = num2str(iops, 6, 1, 0);
 
-       log_info("  %s: io=%sB, bw=%sB/s, iops=%s, runt=%6lumsec\n",
+       log_info("  %s: io=%sB, bw=%sB/s, iops=%s, runt=%6llumsec\n",
                                        ddir_str[ddir], io_p, bw_p, iops_p,
                                        ts->runtime[ddir]);
 
@@ -228,6 +356,11 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
                free(minp);
                free(maxp);
        }
+       if (ts->clat_percentiles) {
+               show_clat_percentiles(ts->io_u_plat[ddir],
+                                       ts->clat_stat[ddir].samples,
+                                       ts->percentile_list);
+       }
        if (calc_lat(&ts->bw_stat[ddir], &min, &max, &mean, &dev)) {
                double p_of_agg;
 
@@ -380,7 +513,7 @@ static void show_ddir_status_terse(struct thread_stat *ts,
        if (ts->runtime[ddir])
                bw = ts->io_bytes[ddir] / ts->runtime[ddir];
 
-       log_info(";%llu;%llu;%lu", ts->io_bytes[ddir] >> 10, bw,
+       log_info(";%llu;%llu;%llu", ts->io_bytes[ddir] >> 10, bw,
                                                        ts->runtime[ddir]);
 
        if (calc_lat(&ts->slat_stat[ddir], &min, &max, &mean, &dev))
@@ -418,12 +551,15 @@ static void show_thread_status_terse(struct thread_stat *ts,
        double usr_cpu, sys_cpu;
        int i;
 
+       /* General Info */
        log_info("%s;%s;%d;%d", FIO_TERSE_VERSION, ts->name, ts->groupid,
                                ts->error);
-
+       /* Log Read Status */
        show_ddir_status_terse(ts, rs, 0);
+       /* Log Write Status */
        show_ddir_status_terse(ts, rs, 1);
 
+       /* CPU Usage */
        if (ts->total_run_time) {
                double runt = (double) ts->total_run_time;
 
@@ -437,22 +573,28 @@ static void show_thread_status_terse(struct thread_stat *ts,
        log_info(";%f%%;%f%%;%lu;%lu;%lu", usr_cpu, sys_cpu, ts->ctx, ts->majf,
                                                                ts->minf);
 
+       /* Calc % distribution of IO depths, usecond, msecond latency */
        stat_calc_dist(ts->io_u_map, ts_total_io_u(ts), io_u_dist);
        stat_calc_lat_u(ts, io_u_lat_u);
        stat_calc_lat_m(ts, io_u_lat_m);
 
+       /* Only show fixed 7 I/O depth levels*/
        log_info(";%3.1f%%;%3.1f%%;%3.1f%%;%3.1f%%;%3.1f%%;%3.1f%%;%3.1f%%",
                        io_u_dist[0], io_u_dist[1], io_u_dist[2], io_u_dist[3],
                        io_u_dist[4], io_u_dist[5], io_u_dist[6]);
 
+       /* Microsecond latency */
        for (i = 0; i < FIO_IO_U_LAT_U_NR; i++)
                log_info(";%3.2f%%", io_u_lat_u[i]);
+       /* Millisecond latency */
        for (i = 0; i < FIO_IO_U_LAT_M_NR; i++)
                log_info(";%3.2f%%", io_u_lat_m[i]);
+       /* Additional output if continue_on_error set - default off*/
        if (ts->continue_on_error)
                log_info(";%lu;%d", ts->total_err_count, ts->first_error);
        log_info("\n");
 
+       /* Additional output if description is set */
        if (ts->description)
                log_info(";%s", ts->description);
 
@@ -465,21 +607,28 @@ static void sum_stat(struct io_stat *dst, struct io_stat *src, int nr)
 
        dst->min_val = min(dst->min_val, src->min_val);
        dst->max_val = max(dst->max_val, src->max_val);
-       dst->samples += src->samples;
 
        /*
-        * Needs a new method for calculating stddev, we cannot just
-        * average them we do below for nr > 1
+        * Compute new mean and S after the merge
+        * <http://en.wikipedia.org/wiki/Algorithms_for_calculating_variance
+        *  #Parallel_algorithm>
         */
        if (nr == 1) {
                mean = src->mean;
                S = src->S;
        } else {
-               mean = ((src->mean * (double) (nr - 1))
-                               + dst->mean) / ((double) nr);
-               S = ((src->S * (double) (nr - 1)) + dst->S) / ((double) nr);
+               double delta = src->mean - dst->mean;
+
+               mean = ((src->mean * src->samples) +
+                       (dst->mean * dst->samples)) /
+                       (dst->samples + src->samples);
+
+               S =  src->S + dst->S + pow(delta, 2.0) *
+                       (dst->samples * src->samples) /
+                       (dst->samples + src->samples);
        }
 
+       dst->samples += src->samples;
        dst->mean = mean;
        dst->S = S;
 }
@@ -549,6 +698,12 @@ void show_run_stats(void)
 
                ts = &threadstats[j];
 
+               ts->clat_percentiles = td->o.clat_percentiles;
+               if (td->o.overwrite_plist)
+                       ts->percentile_list = td->o.percentile_list;
+               else
+                       ts->percentile_list = NULL;
+
                idx++;
                ts->members++;
 
@@ -620,6 +775,10 @@ void show_run_stats(void)
                for (k = 0; k <= 2; k++) {
                        ts->total_io_u[k] += td->ts.total_io_u[k];
                        ts->short_io_u[k] += td->ts.short_io_u[k];
+
+                       int m;
+                       for (m = 0; m < FIO_IO_U_PLAT_NR; m++)
+                               ts->io_u_plat[k][m] += td->ts.io_u_plat[k][m];
                }
 
                ts->total_run_time += td->ts.total_run_time;
@@ -719,7 +878,7 @@ static inline void add_stat_sample(struct io_stat *is, unsigned long data)
 
 static void __add_log_sample(struct io_log *iolog, unsigned long val,
                             enum fio_ddir ddir, unsigned int bs,
-                            unsigned long time)
+                            unsigned long t)
 {
        const int nr_samples = iolog->nr_samples;
 
@@ -731,7 +890,7 @@ static void __add_log_sample(struct io_log *iolog, unsigned long val,
        }
 
        iolog->log[nr_samples].val = val;
-       iolog->log[nr_samples].time = time;
+       iolog->log[nr_samples].time = t;
        iolog->log[nr_samples].ddir = ddir;
        iolog->log[nr_samples].bs = bs;
        iolog->nr_samples++;
@@ -758,6 +917,15 @@ void add_agg_sample(unsigned long val, enum fio_ddir ddir, unsigned int bs)
        __add_log_sample(iolog, val, ddir, bs, mtime_since_genesis());
 }
 
+static void add_clat_percentile_sample(struct thread_stat *ts,
+                               unsigned long usec, enum fio_ddir ddir)
+{
+       unsigned int idx = plat_val_to_idx(usec);
+       assert(idx < FIO_IO_U_PLAT_NR);
+
+       ts->io_u_plat[ddir][idx]++;
+}
+
 void add_clat_sample(struct thread_data *td, enum fio_ddir ddir,
                     unsigned long usec, unsigned int bs)
 {
@@ -770,6 +938,9 @@ void add_clat_sample(struct thread_data *td, enum fio_ddir ddir,
 
        if (ts->clat_log)
                add_log_sample(td, ts->clat_log, usec, ddir, bs);
+
+       if (ts->clat_percentiles)
+               add_clat_percentile_sample(ts, usec, ddir);
 }
 
 void add_slat_sample(struct thread_data *td, enum fio_ddir ddir,