Merge branch 'fixes' of https://github.com/sitsofe/fio
[fio.git] / stat.c
diff --git a/stat.c b/stat.c
index 8770ae28920e5a484cc04ec12579e8b54a777ec5..91c74abef420f8fb0e8453e5a9be1fecff1e6f56 100644 (file)
--- a/stat.c
+++ b/stat.c
@@ -37,9 +37,9 @@ void update_rusage_stat(struct thread_data *td)
        struct thread_stat *ts = &td->ts;
 
        fio_getrusage(&td->ru_end);
-       ts->usr_time += mtime_since(&td->ru_start.ru_utime,
+       ts->usr_time += mtime_since_tv(&td->ru_start.ru_utime,
                                        &td->ru_end.ru_utime);
-       ts->sys_time += mtime_since(&td->ru_start.ru_stime,
+       ts->sys_time += mtime_since_tv(&td->ru_start.ru_stime,
                                        &td->ru_end.ru_stime);
        ts->ctx += td->ru_end.ru_nvcsw + td->ru_end.ru_nivcsw
                        - (td->ru_start.ru_nvcsw + td->ru_start.ru_nivcsw);
@@ -58,7 +58,7 @@ void update_rusage_stat(struct thread_data *td)
  * group by looking at the index bits.
  *
  */
-static unsigned int plat_val_to_idx(unsigned int val)
+static unsigned int plat_val_to_idx(unsigned long long val)
 {
        unsigned int msb, error_bits, base, offset, idx;
 
@@ -66,7 +66,7 @@ static unsigned int plat_val_to_idx(unsigned int val)
        if (val == 0)
                msb = 0;
        else
-               msb = (sizeof(val)*8) - __builtin_clz(val) - 1;
+               msb = (sizeof(val)*8) - __builtin_clzll(val) - 1;
 
        /*
         * MSB <= (FIO_IO_U_PLAT_BITS-1), cannot be rounded off. Use
@@ -100,7 +100,8 @@ static unsigned int plat_val_to_idx(unsigned int val)
  */
 static unsigned long long plat_idx_to_val(unsigned int idx)
 {
-       unsigned int error_bits, k, base;
+       unsigned int error_bits;
+       unsigned long long k, base;
 
        assert(idx < FIO_IO_U_PLAT_NR);
 
@@ -111,7 +112,7 @@ static unsigned long long plat_idx_to_val(unsigned int 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);
+       base = ((unsigned long long) 1) << (error_bits + FIO_IO_U_PLAT_BITS);
 
        /* Find its bucket number of the group */
        k = idx % FIO_IO_U_PLAT_VAL;
@@ -135,16 +136,16 @@ static int double_cmp(const void *a, const void *b)
 }
 
 unsigned int calc_clat_percentiles(unsigned int *io_u_plat, unsigned long nr,
-                                  fio_fp64_t *plist, unsigned int **output,
-                                  unsigned int *maxv, unsigned int *minv)
+                                  fio_fp64_t *plist, unsigned long long **output,
+                                  unsigned long long *maxv, unsigned long long *minv)
 {
        unsigned long sum = 0;
        unsigned int len, i, j = 0;
        unsigned int oval_len = 0;
-       unsigned int *ovals = NULL;
+       unsigned long long *ovals = NULL;
        int is_last;
 
-       *minv = -1U;
+       *minv = -1ULL;
        *maxv = 0;
 
        len = 0;
@@ -173,7 +174,7 @@ unsigned int calc_clat_percentiles(unsigned int *io_u_plat, unsigned long nr,
 
                        if (j == oval_len) {
                                oval_len += 100;
-                               ovals = realloc(ovals, oval_len * sizeof(unsigned int));
+                               ovals = realloc(ovals, oval_len * sizeof(*ovals));
                        }
 
                        ovals[j] = plat_idx_to_val(i);
@@ -201,9 +202,10 @@ static void show_clat_percentiles(unsigned int *io_u_plat, unsigned long nr,
                                  fio_fp64_t *plist, unsigned int precision,
                                  struct buf_output *out)
 {
-       unsigned int len, j = 0, minv, maxv;
-       unsigned int *ovals;
-       int is_last, per_line, scale_down;
+       unsigned int divisor, len, i, j = 0;
+       unsigned long long minv, maxv;
+       unsigned long long *ovals;
+       int is_last, per_line, scale_down, time_width;
        char fmt[32];
 
        len = calc_clat_percentiles(io_u_plat, nr, plist, &ovals, &maxv, &minv);
@@ -211,23 +213,31 @@ static void show_clat_percentiles(unsigned int *io_u_plat, unsigned long nr,
                goto out;
 
        /*
-        * We default to usecs, but if the value range is such that we
-        * should scale down to msecs, do that.
+        * We default to nsecs, but if the value range is such that we
+        * should scale down to usecs or msecs, do that.
         */
-       if (minv > 2000 && maxv > 99999) {
-               scale_down = 1;
+       if (minv > 2000000 && maxv > 99999999ULL) {
+               scale_down = 2;
+               divisor = 1000000;
                log_buf(out, "    clat percentiles (msec):\n     |");
+       } else if (minv > 2000 && maxv > 99999) {
+               scale_down = 1;
+               divisor = 1000;
+               log_buf(out, "    clat percentiles (usec):\n     |");
        } else {
                scale_down = 0;
-               log_buf(out, "    clat percentiles (usec):\n     |");
+               divisor = 1;
+               log_buf(out, "    clat percentiles (nsec):\n     |");
        }
 
-       snprintf(fmt, sizeof(fmt), "%%1.%uf", precision);
-       per_line = (80 - 7) / (precision + 14);
 
-       for (j = 0; j < len; j++) {
-               char fbuf[16], *ptr = fbuf;
+       time_width = max(5, (int) (log10(maxv / divisor) + 1));
+       snprintf(fmt, sizeof(fmt), " %%%u.%ufth=[%%%dllu]%%c", precision + 3,
+                       precision, time_width);
+       /* fmt will be something like " %5.2fth=[%4llu]%c" */
+       per_line = (80 - 7) / (precision + 10 + time_width);
 
+       for (j = 0; j < len; j++) {
                /* for formatting */
                if (j != 0 && (j % per_line) == 0)
                        log_buf(out, "     |");
@@ -235,15 +245,10 @@ static void show_clat_percentiles(unsigned int *io_u_plat, unsigned long nr,
                /* end of the list */
                is_last = (j == len - 1);
 
-               if (plist[j].u.f < 10.0)
-                       ptr += sprintf(fbuf, " ");
-
-               snprintf(ptr, sizeof(fbuf), fmt, plist[j].u.f);
-
-               if (scale_down)
+               for (i = 0; i < scale_down; i++)
                        ovals[j] = (ovals[j] + 999) / 1000;
 
-               log_buf(out, " %sth=[%5u]%c", fbuf, ovals[j], is_last ? '\n' : ',');
+               log_buf(out, fmt, plist[j].u.f, ovals[j], is_last ? '\n' : ',');
 
                if (is_last)
                        break;
@@ -257,8 +262,8 @@ out:
                free(ovals);
 }
 
-bool calc_lat(struct io_stat *is, unsigned long *min, unsigned long *max,
-             double *mean, double *dev)
+bool calc_lat(struct io_stat *is, unsigned long long *min,
+             unsigned long long *max, double *mean, double *dev)
 {
        double n = (double) is->samples;
 
@@ -355,6 +360,28 @@ static void stat_calc_lat(struct thread_stat *ts, double *dst,
        }
 }
 
+/*
+ * To keep the terse format unaltered, add all of the ns latency
+ * buckets to the first us latency bucket
+ */
+void stat_calc_lat_nu(struct thread_stat *ts, double *io_u_lat_u)
+{
+       unsigned long ntotal = 0, total = ddir_rw_sum(ts->total_io_u);
+       int i;
+
+       stat_calc_lat(ts, io_u_lat_u, ts->io_u_lat_u, FIO_IO_U_LAT_U_NR);
+
+       for (i = 0; i < FIO_IO_U_LAT_N_NR; i++)
+               ntotal += ts->io_u_lat_n[i];
+
+       io_u_lat_u[0] += 100.0 * (double) ntotal / (double) total;
+}
+
+void stat_calc_lat_n(struct thread_stat *ts, double *io_u_lat)
+{
+       stat_calc_lat(ts, io_u_lat, ts->io_u_lat_n, FIO_IO_U_LAT_N_NR);
+}
+
 void stat_calc_lat_u(struct thread_stat *ts, double *io_u_lat)
 {
        stat_calc_lat(ts, io_u_lat, ts->io_u_lat_u, FIO_IO_U_LAT_U_NR);
@@ -365,14 +392,17 @@ void stat_calc_lat_m(struct thread_stat *ts, double *io_u_lat)
        stat_calc_lat(ts, io_u_lat, ts->io_u_lat_m, FIO_IO_U_LAT_M_NR);
 }
 
-static void display_lat(const char *name, unsigned long min, unsigned long max,
-                       double mean, double dev, struct buf_output *out)
+static void display_lat(const char *name, unsigned long long min,
+                       unsigned long long max, double mean, double dev,
+                       struct buf_output *out)
 {
-       const char *base = "(usec)";
+       const char *base = "(nsec)";
        char *minp, *maxp;
 
-       if (usec_to_msec(&min, &max, &mean, &dev))
+       if (nsec_to_msec(&min, &max, &mean, &dev))
                base = "(msec)";
+       else if (nsec_to_usec(&min, &max, &mean, &dev))
+               base = "(usec)";
 
        minp = num2str(min, 6, 1, 0, N2S_NONE);
        maxp = num2str(max, 6, 1, 0, N2S_NONE);
@@ -388,8 +418,8 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
                             int ddir, struct buf_output *out)
 {
        const char *str[] = { " read", "write", " trim" };
-       unsigned long min, max, runt;
-       unsigned long long bw, iops;
+       unsigned long runt;
+       unsigned long long min, max, bw, iops;
        double mean, dev;
        char *io_p, *bw_p, *bw_p_alt, *iops_p;
        int i2p;
@@ -446,6 +476,12 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
                else
                        bw_str = "kB";
 
+               if (rs->agg[ddir]) {
+                       p_of_agg = mean * 100 / (double) (rs->agg[ddir] / 1024);
+                       if (p_of_agg > 100.0)
+                               p_of_agg = 100.0;
+               }
+
                if (rs->unit_base == 1) {
                        min *= 8.0;
                        max *= 8.0;
@@ -453,12 +489,6 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
                        dev *= 8.0;
                }
 
-               if (rs->agg[ddir]) {
-                       p_of_agg = mean * 100 / (double) rs->agg[ddir];
-                       if (p_of_agg > 100.0)
-                               p_of_agg = 100.0;
-               }
-
                if (mean > fkb_base * fkb_base) {
                        min /= fkb_base;
                        max /= fkb_base;
@@ -467,8 +497,15 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
                        bw_str = (rs->unit_base == 1 ? "Mibit" : "MiB");
                }
 
-               log_buf(out, "   bw (%5s/s): min=%5lu, max=%5lu, per=%3.2f%%, avg=%5.02f, stdev=%5.02f\n",
-                       bw_str, min, max, p_of_agg, mean, dev);
+               log_buf(out, "   bw (%5s/s): min=%5llu, max=%5llu, per=%3.2f%%, "
+                       "avg=%5.02f, stdev=%5.02f, samples=%" PRIu64 "\n",
+                       bw_str, min, max, p_of_agg, mean, dev,
+                       (&ts->bw_stat[ddir])->samples);
+       }
+       if (calc_lat(&ts->iops_stat[ddir], &min, &max, &mean, &dev)) {
+               log_buf(out, "   iops        : min=%5llu, max=%5llu, "
+                       "avg=%5.02f, stdev=%5.02f, samples=%" PRIu64 "\n",
+                       min, max, mean, dev, (&ts->iops_stat[ddir])->samples);
        }
 }
 
@@ -484,7 +521,7 @@ static int show_lat(double *io_u_lat, int nr, const char **ranges,
                if (new_line) {
                        if (line)
                                log_buf(out, "\n");
-                       log_buf(out, "    lat (%s) : ", msg);
+                       log_buf(out, "  lat (%s)   : ", msg);
                        new_line = 0;
                        line = 0;
                }
@@ -502,6 +539,14 @@ static int show_lat(double *io_u_lat, int nr, const char **ranges,
        return shown;
 }
 
+static void show_lat_n(double *io_u_lat_n, struct buf_output *out)
+{
+       const char *ranges[] = { "2=", "4=", "10=", "20=", "50=", "100=",
+                                "250=", "500=", "750=", "1000=", };
+
+       show_lat(io_u_lat_n, FIO_IO_U_LAT_N_NR, ranges, "nsec", out);
+}
+
 static void show_lat_u(double *io_u_lat_u, struct buf_output *out)
 {
        const char *ranges[] = { "2=", "4=", "10=", "20=", "50=", "100=",
@@ -521,12 +566,15 @@ static void show_lat_m(double *io_u_lat_m, struct buf_output *out)
 
 static void show_latencies(struct thread_stat *ts, struct buf_output *out)
 {
+       double io_u_lat_n[FIO_IO_U_LAT_N_NR];
        double io_u_lat_u[FIO_IO_U_LAT_U_NR];
        double io_u_lat_m[FIO_IO_U_LAT_M_NR];
 
+       stat_calc_lat_n(ts, io_u_lat_n);
        stat_calc_lat_u(ts, io_u_lat_u);
        stat_calc_lat_m(ts, io_u_lat_m);
 
+       show_lat_n(io_u_lat_n, out);
        show_lat_u(io_u_lat_u, out);
        show_lat_m(io_u_lat_m, out);
 }
@@ -816,14 +864,13 @@ static void show_thread_status_normal(struct thread_stat *ts,
 
 static void show_ddir_status_terse(struct thread_stat *ts,
                                   struct group_run_stats *rs, int ddir,
-                                  struct buf_output *out)
+                                  int ver, struct buf_output *out)
 {
-       unsigned long min, max;
-       unsigned long long bw, iops;
-       unsigned int *ovals = NULL;
+       unsigned long long min, max, minv, maxv, bw, iops;
+       unsigned long long *ovals = NULL;
        double mean, dev;
-       unsigned int len, minv, maxv;
-       int i;
+       unsigned int len;
+       int i, bw_stat;
 
        assert(ddir_rw(ddir));
 
@@ -840,14 +887,14 @@ static void show_ddir_status_terse(struct thread_stat *ts,
                                        (unsigned long long) ts->runtime[ddir]);
 
        if (calc_lat(&ts->slat_stat[ddir], &min, &max, &mean, &dev))
-               log_buf(out, ";%lu;%lu;%f;%f", min, max, mean, dev);
+               log_buf(out, ";%llu;%llu;%f;%f", min/1000, max/1000, mean/1000, dev/1000);
        else
-               log_buf(out, ";%lu;%lu;%f;%f", 0UL, 0UL, 0.0, 0.0);
+               log_buf(out, ";%llu;%llu;%f;%f", 0ULL, 0ULL, 0.0, 0.0);
 
        if (calc_lat(&ts->clat_stat[ddir], &min, &max, &mean, &dev))
-               log_buf(out, ";%lu;%lu;%f;%f", min, max, mean, dev);
+               log_buf(out, ";%llu;%llu;%f;%f", min/1000, max/1000, mean/1000, dev/1000);
        else
-               log_buf(out, ";%lu;%lu;%f;%f", 0UL, 0UL, 0.0, 0.0);
+               log_buf(out, ";%llu;%llu;%f;%f", 0ULL, 0ULL, 0.0, 0.0);
 
        if (ts->clat_percentiles) {
                len = calc_clat_percentiles(ts->io_u_plat[ddir],
@@ -862,39 +909,53 @@ static void show_ddir_status_terse(struct thread_stat *ts,
                        log_buf(out, ";0%%=0");
                        continue;
                }
-               log_buf(out, ";%f%%=%u", ts->percentile_list[i].u.f, ovals[i]);
+               log_buf(out, ";%f%%=%llu", ts->percentile_list[i].u.f, ovals[i]/1000);
        }
 
        if (calc_lat(&ts->lat_stat[ddir], &min, &max, &mean, &dev))
-               log_buf(out, ";%lu;%lu;%f;%f", min, max, mean, dev);
+               log_buf(out, ";%llu;%llu;%f;%f", min/1000, max/1000, mean/1000, dev/1000);
        else
-               log_buf(out, ";%lu;%lu;%f;%f", 0UL, 0UL, 0.0, 0.0);
+               log_buf(out, ";%llu;%llu;%f;%f", 0ULL, 0ULL, 0.0, 0.0);
 
        if (ovals)
                free(ovals);
 
-       if (calc_lat(&ts->bw_stat[ddir], &min, &max, &mean, &dev)) {
+       bw_stat = calc_lat(&ts->bw_stat[ddir], &min, &max, &mean, &dev);
+       if (bw_stat) {
                double p_of_agg = 100.0;
 
                if (rs->agg[ddir]) {
-                       p_of_agg = mean * 100 / (double) rs->agg[ddir];
+                       p_of_agg = mean * 100 / (double) (rs->agg[ddir] / 1024);
                        if (p_of_agg > 100.0)
                                p_of_agg = 100.0;
                }
 
-               log_buf(out, ";%lu;%lu;%f%%;%f;%f", min, max, p_of_agg, mean, dev);
+               log_buf(out, ";%llu;%llu;%f%%;%f;%f", min, max, p_of_agg, mean, dev);
        } else
-               log_buf(out, ";%lu;%lu;%f%%;%f;%f", 0UL, 0UL, 0.0, 0.0, 0.0);
+               log_buf(out, ";%llu;%llu;%f%%;%f;%f", 0ULL, 0ULL, 0.0, 0.0, 0.0);
+
+       if (ver == 5) {
+               if (bw_stat)
+                       log_buf(out, ";%" PRIu64, (&ts->bw_stat[ddir])->samples);
+               else
+                       log_buf(out, ";%lu", 0UL);
+
+               if (calc_lat(&ts->iops_stat[ddir], &min, &max, &mean, &dev))
+                       log_buf(out, ";%llu;%llu;%f;%f;%" PRIu64, min, max,
+                               mean, dev, (&ts->iops_stat[ddir])->samples);
+               else
+                       log_buf(out, ";%llu;%llu;%f;%f;%lu", 0ULL, 0ULL, 0.0, 0.0, 0UL);
+       }
 }
 
 static void add_ddir_status_json(struct thread_stat *ts,
                struct group_run_stats *rs, int ddir, struct json_object *parent)
 {
-       unsigned long min, max;
+       unsigned long long min, max, minv, maxv;
        unsigned long long bw;
-       unsigned int *ovals = NULL;
+       unsigned long long *ovals = NULL;
        double mean, dev, iops;
-       unsigned int len, minv, maxv;
+       unsigned int len;
        int i;
        const char *ddirname[] = {"read", "write", "trim"};
        struct json_object *dir_object, *tmp_object, *percentile_object, *clat_bins_object;
@@ -919,7 +980,8 @@ static void add_ddir_status_json(struct thread_stat *ts,
                iops = (1000.0 * (uint64_t) ts->total_io_u[ddir]) / runt;
        }
 
-       json_object_add_value_int(dir_object, "io_bytes", ts->io_bytes[ddir] >> 10);
+       json_object_add_value_int(dir_object, "io_bytes", ts->io_bytes[ddir]);
+       json_object_add_value_int(dir_object, "io_kbytes", ts->io_bytes[ddir] >> 10);
        json_object_add_value_int(dir_object, "bw", bw);
        json_object_add_value_float(dir_object, "iops", iops);
        json_object_add_value_int(dir_object, "runtime", ts->runtime[ddir]);
@@ -932,7 +994,7 @@ static void add_ddir_status_json(struct thread_stat *ts,
                mean = dev = 0.0;
        }
        tmp_object = json_create_object();
-       json_object_add_value_object(dir_object, "slat", tmp_object);
+       json_object_add_value_object(dir_object, "slat_ns", tmp_object);
        json_object_add_value_int(tmp_object, "min", min);
        json_object_add_value_int(tmp_object, "max", max);
        json_object_add_value_float(tmp_object, "mean", mean);
@@ -943,7 +1005,7 @@ static void add_ddir_status_json(struct thread_stat *ts,
                mean = dev = 0.0;
        }
        tmp_object = json_create_object();
-       json_object_add_value_object(dir_object, "clat", tmp_object);
+       json_object_add_value_object(dir_object, "clat_ns", tmp_object);
        json_object_add_value_int(tmp_object, "min", min);
        json_object_add_value_int(tmp_object, "max", max);
        json_object_add_value_float(tmp_object, "mean", mean);
@@ -984,7 +1046,7 @@ static void add_ddir_status_json(struct thread_stat *ts,
                mean = dev = 0.0;
        }
        tmp_object = json_create_object();
-       json_object_add_value_object(dir_object, "lat", tmp_object);
+       json_object_add_value_object(dir_object, "lat_ns", tmp_object);
        json_object_add_value_int(tmp_object, "min", min);
        json_object_add_value_int(tmp_object, "max", max);
        json_object_add_value_float(tmp_object, "mean", mean);
@@ -994,7 +1056,7 @@ static void add_ddir_status_json(struct thread_stat *ts,
 
        if (calc_lat(&ts->bw_stat[ddir], &min, &max, &mean, &dev)) {
                if (rs->agg[ddir]) {
-                       p_of_agg = mean * 100 / (double) rs->agg[ddir];
+                       p_of_agg = mean * 100 / (double) (rs->agg[ddir] / 1024);
                        if (p_of_agg > 100.0)
                                p_of_agg = 100.0;
                }
@@ -1007,74 +1069,24 @@ static void add_ddir_status_json(struct thread_stat *ts,
        json_object_add_value_float(dir_object, "bw_agg", p_of_agg);
        json_object_add_value_float(dir_object, "bw_mean", mean);
        json_object_add_value_float(dir_object, "bw_dev", dev);
-}
+       json_object_add_value_int(dir_object, "bw_samples",
+                               (&ts->bw_stat[ddir])->samples);
 
-static void show_thread_status_terse_v2(struct thread_stat *ts,
-                                       struct group_run_stats *rs,
-                                       struct buf_output *out)
-{
-       double io_u_dist[FIO_IO_U_MAP_NR];
-       double io_u_lat_u[FIO_IO_U_LAT_U_NR];
-       double io_u_lat_m[FIO_IO_U_LAT_M_NR];
-       double usr_cpu, sys_cpu;
-       int i;
-
-       /* General Info */
-       log_buf(out, "2;%s;%d;%d", ts->name, ts->groupid, ts->error);
-       /* Log Read Status */
-       show_ddir_status_terse(ts, rs, DDIR_READ, out);
-       /* Log Write Status */
-       show_ddir_status_terse(ts, rs, DDIR_WRITE, out);
-       /* Log Trim Status */
-       show_ddir_status_terse(ts, rs, DDIR_TRIM, out);
-
-       /* CPU Usage */
-       if (ts->total_run_time) {
-               double runt = (double) ts->total_run_time;
-
-               usr_cpu = (double) ts->usr_time * 100 / runt;
-               sys_cpu = (double) ts->sys_time * 100 / runt;
-       } else {
-               usr_cpu = 0;
-               sys_cpu = 0;
+       if (!calc_lat(&ts->iops_stat[ddir], &min, &max, &mean, &dev)) {
+               min = max = 0;
+               mean = dev = 0.0;
        }
-
-       log_buf(out, ";%f%%;%f%%;%llu;%llu;%llu", usr_cpu, sys_cpu,
-                                               (unsigned long long) ts->ctx,
-                                               (unsigned long long) ts->majf,
-                                               (unsigned long long) ts->minf);
-
-       /* Calc % distribution of IO depths, usecond, msecond latency */
-       stat_calc_dist(ts->io_u_map, ddir_rw_sum(ts->total_io_u), 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_buf(out, ";%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_buf(out, ";%3.2f%%", io_u_lat_u[i]);
-       /* Millisecond latency */
-       for (i = 0; i < FIO_IO_U_LAT_M_NR; i++)
-               log_buf(out, ";%3.2f%%", io_u_lat_m[i]);
-       /* Additional output if continue_on_error set - default off*/
-       if (ts->continue_on_error)
-               log_buf(out, ";%llu;%d", (unsigned long long) ts->total_err_count, ts->first_error);
-       log_buf(out, "\n");
-
-       /* Additional output if description is set */
-       if (strlen(ts->description))
-               log_buf(out, ";%s", ts->description);
-
-       log_buf(out, "\n");
+       json_object_add_value_int(dir_object, "iops_min", min);
+       json_object_add_value_int(dir_object, "iops_max", max);
+       json_object_add_value_float(dir_object, "iops_mean", mean);
+       json_object_add_value_float(dir_object, "iops_stddev", dev);
+       json_object_add_value_int(dir_object, "iops_samples",
+                               (&ts->iops_stat[ddir])->samples);
 }
 
-static void show_thread_status_terse_v3_v4(struct thread_stat *ts,
-                                          struct group_run_stats *rs, int ver,
-                                          struct buf_output *out)
+static void show_thread_status_terse_all(struct thread_stat *ts,
+                                        struct group_run_stats *rs, int ver,
+                                        struct buf_output *out)
 {
        double io_u_dist[FIO_IO_U_MAP_NR];
        double io_u_lat_u[FIO_IO_U_LAT_U_NR];
@@ -1083,15 +1095,19 @@ static void show_thread_status_terse_v3_v4(struct thread_stat *ts,
        int i;
 
        /* General Info */
-       log_buf(out, "%d;%s;%s;%d;%d", ver, fio_version_string,
-                                       ts->name, ts->groupid, ts->error);
+       if (ver == 2)
+               log_buf(out, "2;%s;%d;%d", ts->name, ts->groupid, ts->error);
+       else
+               log_buf(out, "%d;%s;%s;%d;%d", ver, fio_version_string,
+                       ts->name, ts->groupid, ts->error);
+
        /* Log Read Status */
-       show_ddir_status_terse(ts, rs, DDIR_READ, out);
+       show_ddir_status_terse(ts, rs, DDIR_READ, ver, out);
        /* Log Write Status */
-       show_ddir_status_terse(ts, rs, DDIR_WRITE, out);
+       show_ddir_status_terse(ts, rs, DDIR_WRITE, ver, out);
        /* Log Trim Status */
-       if (ver == 4)
-               show_ddir_status_terse(ts, rs, DDIR_TRIM, out);
+       if (ver == 2 || ver == 4 || ver == 5)
+               show_ddir_status_terse(ts, rs, DDIR_TRIM, ver, out);
 
        /* CPU Usage */
        if (ts->total_run_time) {
@@ -1111,7 +1127,7 @@ static void show_thread_status_terse_v3_v4(struct thread_stat *ts,
 
        /* Calc % distribution of IO depths, usecond, msecond latency */
        stat_calc_dist(ts->io_u_map, ddir_rw_sum(ts->total_io_u), io_u_dist);
-       stat_calc_lat_u(ts, io_u_lat_u);
+       stat_calc_lat_nu(ts, io_u_lat_u);
        stat_calc_lat_m(ts, io_u_lat_m);
 
        /* Only show fixed 7 I/O depth levels*/
@@ -1127,11 +1143,14 @@ static void show_thread_status_terse_v3_v4(struct thread_stat *ts,
                log_buf(out, ";%3.2f%%", io_u_lat_m[i]);
 
        /* disk util stats, if any */
-       show_disk_util(1, NULL, out);
+       if (ver >= 3)
+               show_disk_util(1, NULL, out);
 
        /* Additional output if continue_on_error set - default off*/
        if (ts->continue_on_error)
                log_buf(out, ";%llu;%d", (unsigned long long) ts->total_err_count, ts->first_error);
+       if (ver == 2)
+               log_buf(out, "\n");
 
        /* Additional output if description is set */
        if (strlen(ts->description))
@@ -1172,6 +1191,7 @@ static struct json_object *show_thread_status_json(struct thread_stat *ts,
        struct json_object *root, *tmp;
        struct jobs_eta *je;
        double io_u_dist[FIO_IO_U_MAP_NR];
+       double io_u_lat_n[FIO_IO_U_LAT_N_NR];
        double io_u_lat_u[FIO_IO_U_LAT_U_NR];
        double io_u_lat_m[FIO_IO_U_LAT_M_NR];
        double usr_cpu, sys_cpu;
@@ -1216,6 +1236,7 @@ static struct json_object *show_thread_status_json(struct thread_stat *ts,
 
        /* Calc % distribution of IO depths, usecond, msecond latency */
        stat_calc_dist(ts->io_u_map, ddir_rw_sum(ts->total_io_u), io_u_dist);
+       stat_calc_lat_n(ts, io_u_lat_n);
        stat_calc_lat_u(ts, io_u_lat_u);
        stat_calc_lat_m(ts, io_u_lat_m);
 
@@ -1231,9 +1252,17 @@ static struct json_object *show_thread_status_json(struct thread_stat *ts,
                json_object_add_value_float(tmp, (const char *)name, io_u_dist[i]);
        }
 
+       /* Nanosecond latency */
        tmp = json_create_object();
-       json_object_add_value_object(root, "latency_us", tmp);
+       json_object_add_value_object(root, "latency_ns", tmp);
+       for (i = 0; i < FIO_IO_U_LAT_N_NR; i++) {
+               const char *ranges[] = { "2", "4", "10", "20", "50", "100",
+                                "250", "500", "750", "1000", };
+               json_object_add_value_float(tmp, ranges[i], io_u_lat_n[i]);
+       }
        /* Microsecond latency */
+       tmp = json_create_object();
+       json_object_add_value_object(root, "latency_us", tmp);
        for (i = 0; i < FIO_IO_U_LAT_U_NR; i++) {
                const char *ranges[] = { "2", "4", "10", "20", "50", "100",
                                 "250", "500", "750", "1000", };
@@ -1362,10 +1391,8 @@ static void show_thread_status_terse(struct thread_stat *ts,
                                     struct group_run_stats *rs,
                                     struct buf_output *out)
 {
-       if (terse_version == 2)
-               show_thread_status_terse_v2(ts, rs, out);
-       else if (terse_version == 3 || terse_version == 4)
-               show_thread_status_terse_v3_v4(ts, rs, terse_version, out);
+       if (terse_version >= 2 && terse_version <= 5)
+               show_thread_status_terse_all(ts, rs, terse_version, out);
        else
                log_err("fio: bad terse version!? %d\n", terse_version);
 }
@@ -1457,6 +1484,7 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src,
                        sum_stat(&dst->slat_stat[l], &src->slat_stat[l], first);
                        sum_stat(&dst->lat_stat[l], &src->lat_stat[l], first);
                        sum_stat(&dst->bw_stat[l], &src->bw_stat[l], first);
+                       sum_stat(&dst->iops_stat[l], &src->iops_stat[l], first);
 
                        dst->io_bytes[l] += src->io_bytes[l];
 
@@ -1467,6 +1495,7 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src,
                        sum_stat(&dst->slat_stat[0], &src->slat_stat[l], first);
                        sum_stat(&dst->lat_stat[0], &src->lat_stat[l], first);
                        sum_stat(&dst->bw_stat[0], &src->bw_stat[l], first);
+                       sum_stat(&dst->iops_stat[0], &src->iops_stat[l], first);
 
                        dst->io_bytes[0] += src->io_bytes[l];
 
@@ -1493,6 +1522,8 @@ void sum_thread_stats(struct thread_stat *dst, struct thread_stat *src,
                dst->io_u_submit[k] += src->io_u_submit[k];
        for (k = 0; k < FIO_IO_U_MAP_NR; k++)
                dst->io_u_complete[k] += src->io_u_complete[k];
+       for (k = 0; k < FIO_IO_U_LAT_N_NR; k++)
+               dst->io_u_lat_n[k] += src->io_u_lat_n[k];
        for (k = 0; k < FIO_IO_U_LAT_U_NR; k++)
                dst->io_u_lat_u[k] += src->io_u_lat_u[k];
        for (k = 0; k < FIO_IO_U_LAT_M_NR; k++)
@@ -1546,6 +1577,7 @@ void init_thread_stat(struct thread_stat *ts)
                ts->clat_stat[j].min_val = -1UL;
                ts->slat_stat[j].min_val = -1UL;
                ts->bw_stat[j].min_val = -1UL;
+               ts->iops_stat[j].min_val = -1UL;
        }
        ts->groupid = -1;
 }
@@ -1825,8 +1857,10 @@ void __show_run_stats(void)
        }
 
        for (i = 0; i < FIO_OUTPUT_NR; i++) {
-               buf_output_flush(&output[i]);
-               buf_output_free(&output[i]);
+               struct buf_output *out = &output[i];
+
+               log_info_buf(out->buf, out->buflen);
+               buf_output_free(out);
        }
 
        log_info_flush();
@@ -1846,22 +1880,22 @@ void __show_running_run_stats(void)
 {
        struct thread_data *td;
        unsigned long long *rt;
-       struct timeval tv;
+       struct timespec ts;
        int i;
 
        fio_mutex_down(stat_mutex);
 
        rt = malloc(thread_number * sizeof(unsigned long long));
-       fio_gettime(&tv, NULL);
+       fio_gettime(&ts, NULL);
 
        for_each_td(td, i) {
                td->update_rusage = 1;
                td->ts.io_bytes[DDIR_READ] = td->io_bytes[DDIR_READ];
                td->ts.io_bytes[DDIR_WRITE] = td->io_bytes[DDIR_WRITE];
                td->ts.io_bytes[DDIR_TRIM] = td->io_bytes[DDIR_TRIM];
-               td->ts.total_run_time = mtime_since(&td->epoch, &tv);
+               td->ts.total_run_time = mtime_since(&td->epoch, &ts);
 
-               rt[i] = mtime_since(&td->start, &tv);
+               rt[i] = mtime_since(&td->start, &ts);
                if (td_read(td) && td->ts.io_bytes[DDIR_READ])
                        td->ts.runtime[DDIR_READ] += rt[i];
                if (td_write(td) && td->ts.io_bytes[DDIR_WRITE])
@@ -1896,7 +1930,7 @@ void __show_running_run_stats(void)
 }
 
 static int status_interval_init;
-static struct timeval status_time;
+static struct timespec status_time;
 static int status_file_disabled;
 
 #define FIO_STATUS_FILE                "fio-dump-status"
@@ -1952,7 +1986,7 @@ void check_for_running_stats(void)
        }
 }
 
-static inline void add_stat_sample(struct io_stat *is, unsigned long data)
+static inline void add_stat_sample(struct io_stat *is, unsigned long long data)
 {
        double val = data;
        double delta;
@@ -2171,6 +2205,9 @@ void reset_io_stats(struct thread_data *td)
 
                ts->io_bytes[i] = 0;
                ts->runtime[i] = 0;
+               ts->total_io_u[i] = 0;
+               ts->short_io_u[i] = 0;
+               ts->drop_io_u[i] = 0;
 
                for (j = 0; j < FIO_IO_U_PLAT_NR; j++)
                        ts->io_u_plat[i][j] = 0;
@@ -2180,17 +2217,17 @@ void reset_io_stats(struct thread_data *td)
                ts->io_u_map[i] = 0;
                ts->io_u_submit[i] = 0;
                ts->io_u_complete[i] = 0;
+       }
+
+       for (i = 0; i < FIO_IO_U_LAT_N_NR; i++)
+               ts->io_u_lat_n[i] = 0;
+       for (i = 0; i < FIO_IO_U_LAT_U_NR; i++)
                ts->io_u_lat_u[i] = 0;
+       for (i = 0; i < FIO_IO_U_LAT_M_NR; i++)
                ts->io_u_lat_m[i] = 0;
-               ts->total_submit = 0;
-               ts->total_complete = 0;
-       }
 
-       for (i = 0; i < 3; i++) {
-               ts->total_io_u[i] = 0;
-               ts->short_io_u[i] = 0;
-               ts->drop_io_u[i] = 0;
-       }
+       ts->total_submit = 0;
+       ts->total_complete = 0;
 }
 
 static void __add_stat_to_log(struct io_log *iolog, enum fio_ddir ddir,
@@ -2299,16 +2336,16 @@ void add_agg_sample(union io_sample_data data, enum fio_ddir ddir, unsigned int
 }
 
 static void add_clat_percentile_sample(struct thread_stat *ts,
-                               unsigned long usec, enum fio_ddir ddir)
+                               unsigned long long nsec, enum fio_ddir ddir)
 {
-       unsigned int idx = plat_val_to_idx(usec);
+       unsigned int idx = plat_val_to_idx(nsec);
        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, uint64_t offset)
+                    unsigned long long nsec, unsigned int bs, uint64_t offset)
 {
        unsigned long elapsed, this_window;
        struct thread_stat *ts = &td->ts;
@@ -2316,14 +2353,14 @@ void add_clat_sample(struct thread_data *td, enum fio_ddir ddir,
 
        td_io_u_lock(td);
 
-       add_stat_sample(&ts->clat_stat[ddir], usec);
+       add_stat_sample(&ts->clat_stat[ddir], nsec);
 
        if (td->clat_log)
-               add_log_sample(td, td->clat_log, sample_val(usec), ddir, bs,
+               add_log_sample(td, td->clat_log, sample_val(nsec), ddir, bs,
                               offset);
 
        if (ts->clat_percentiles)
-               add_clat_percentile_sample(ts, usec, ddir);
+               add_clat_percentile_sample(ts, nsec, ddir);
 
        if (iolog && iolog->hist_msec) {
                struct io_hist *hw = &iolog->hist_window[ddir];
@@ -2385,7 +2422,7 @@ void add_slat_sample(struct thread_data *td, enum fio_ddir ddir,
 }
 
 void add_lat_sample(struct thread_data *td, enum fio_ddir ddir,
-                   unsigned long usec, unsigned int bs, uint64_t offset)
+                   unsigned long long nsec, unsigned int bs, uint64_t offset)
 {
        struct thread_stat *ts = &td->ts;
 
@@ -2394,23 +2431,23 @@ void add_lat_sample(struct thread_data *td, enum fio_ddir ddir,
 
        td_io_u_lock(td);
 
-       add_stat_sample(&ts->lat_stat[ddir], usec);
+       add_stat_sample(&ts->lat_stat[ddir], nsec);
 
        if (td->lat_log)
-               add_log_sample(td, td->lat_log, sample_val(usec), ddir, bs,
+               add_log_sample(td, td->lat_log, sample_val(nsec), ddir, bs,
                               offset);
 
        td_io_u_unlock(td);
 }
 
 void add_bw_sample(struct thread_data *td, struct io_u *io_u,
-                  unsigned int bytes, unsigned long spent)
+                  unsigned int bytes, unsigned long long spent)
 {
        struct thread_stat *ts = &td->ts;
        unsigned long rate;
 
        if (spent)
-               rate = bytes * 1000 / spent;
+               rate = (unsigned long) (bytes * 1000000ULL / spent);
        else
                rate = 0;
 
@@ -2426,8 +2463,8 @@ void add_bw_sample(struct thread_data *td, struct io_u *io_u,
        td_io_u_unlock(td);
 }
 
-static int __add_samples(struct thread_data *td, struct timeval *parent_tv,
-                        struct timeval *t, unsigned int avg_time,
+static int __add_samples(struct thread_data *td, struct timespec *parent_tv,
+                        struct timespec *t, unsigned int avg_time,
                         uint64_t *this_io_bytes, uint64_t *stat_io_bytes,
                         struct io_stat *stat, struct io_log *log,
                         bool is_kb)
@@ -2464,7 +2501,7 @@ static int __add_samples(struct thread_data *td, struct timeval *parent_tv,
 
                add_stat_sample(&stat[ddir], rate);
 
-               if (td->bw_log) {
+               if (log) {
                        unsigned int bs = 0;
 
                        if (td->o.min_bs[ddir] == td->o.max_bs[ddir])
@@ -2477,7 +2514,7 @@ static int __add_samples(struct thread_data *td, struct timeval *parent_tv,
                stat_io_bytes[ddir] = this_io_bytes[ddir];
        }
 
-       timeval_add_msec(parent_tv, avg_time);
+       timespec_add_msec(parent_tv, avg_time);
 
        td_io_u_unlock(td);
 
@@ -2489,7 +2526,7 @@ static int __add_samples(struct thread_data *td, struct timeval *parent_tv,
        return min(next, next_log);
 }
 
-static int add_bw_samples(struct thread_data *td, struct timeval *t)
+static int add_bw_samples(struct thread_data *td, struct timespec *t)
 {
        return __add_samples(td, &td->bw_sample_time, t, td->o.bw_avg_time,
                                td->this_io_bytes, td->stat_io_bytes,
@@ -2513,7 +2550,7 @@ void add_iops_sample(struct thread_data *td, struct io_u *io_u,
        td_io_u_unlock(td);
 }
 
-static int add_iops_samples(struct thread_data *td, struct timeval *t)
+static int add_iops_samples(struct thread_data *td, struct timespec *t)
 {
        return __add_samples(td, &td->iops_sample_time, t, td->o.iops_avg_time,
                                td->this_io_blocks, td->stat_io_blocks,
@@ -2527,7 +2564,7 @@ int calc_log_samples(void)
 {
        struct thread_data *td;
        unsigned int next = ~0U, tmp;
-       struct timeval now;
+       struct timespec now;
        int i;
 
        fio_gettime(&now, NULL);
@@ -2540,12 +2577,14 @@ int calc_log_samples(void)
                        next = min(td->o.iops_avg_time, td->o.bw_avg_time);
                        continue;
                }
-               if (td->bw_log && !per_unit_log(td->bw_log)) {
+               if (!td->bw_log ||
+                       (td->bw_log && !per_unit_log(td->bw_log))) {
                        tmp = add_bw_samples(td, &now);
                        if (tmp < next)
                                next = tmp;
                }
-               if (td->iops_log && !per_unit_log(td->iops_log)) {
+               if (!td->iops_log ||
+                       (td->iops_log && !per_unit_log(td->iops_log))) {
                        tmp = add_iops_samples(td, &now);
                        if (tmp < next)
                                next = tmp;