Add support for write_iops_log

Signed-off-by: Jens Axboe <axboe@kernel.dk>

diff --git a/HOWTO b/HOWTO
index cc2df9b72421486d96d47e2d72220a0a5848c55a..24a0f3b09baed3951e85ac9e54185e181f81b073 100644 (file)
--- a/HOWTO
+++ b/HOWTO
@@ -864,6 +864,9 @@ exitall             When one job finishes, terminate the rest. The default is
 bwavgtime=int  Average the calculated bandwidth over the given time. Value
                is specified in milliseconds.
 
+iopsavgtime=int        Average the calculated IOPS over the given time. Value
+               is specified in milliseconds.
+
 create_serialize=bool  If true, serialize the file creating for the jobs.
                        This may be handy to avoid interleaving of data
                        files, which may greatly depend on the filesystem
@@ -1104,6 +1107,9 @@ write_lat_log=str Same as write_bw_log, except that this option stores io
                and foo_lat.log. This helps fio_generate_plot fine the logs
                automatically.
 
+write_bw_log=str If given, write an IOPS log of the jobs in this job
+               file. See write_bw_log.
+
 lockmem=int    Pin down the specified amount of memory with mlock(2). Can
                potentially be used instead of removing memory or booting
                with less memory to simulate a smaller amount of memory.

diff --git a/fio.1 b/fio.1
index dc10b4031d9260817618033dc95218c73c96c446..0baa4295a0d8406313d8e87ddd85f45a58ad5172 100644 (file)
--- a/fio.1
+++ b/fio.1
@@ -673,6 +673,10 @@ Terminate all jobs when one finishes.  Default: wait for each job to finish.
 Average bandwidth calculations over the given time in milliseconds.  Default:
 500ms.
 .TP
+.BI iopsavgtime \fR=\fPint
+Average IOPS calculations over the given time in milliseconds.  Default:
+500ms.
+.TP
 .BI create_serialize \fR=\fPbool
 If true, serialize file creation for the jobs.  Default: true.
 .TP
@@ -845,6 +849,11 @@ Same as \fBwrite_bw_log\fR, but writes I/O completion latencies.  If no
 filename is given with this option, the default filename of "jobname_type.log"
 is used. Even if the filename is given, fio will still append the type of log.
 .TP
+.BI write_iops_log \fR=\fPstr
+Same as \fBwrite_bw_log\fR, but writes IOPS. If no filename is given with this
+option, the default filename of "jobname_type.log" is used. Even if the
+filename is given, fio will still append the type of log.
+.TP
 .BI disable_lat \fR=\fPbool
 Disable measurements of total latency numbers. Useful only for cutting
 back the number of calls to gettimeofday, as that does impact performance at

diff --git a/fio.c b/fio.c
index 61ef88b315eb6da4ace155967d8f1bce19eee716..d6802e0aea4c702cf6f591fb768ff96b49123f0d 100644 (file)
--- a/fio.c
+++ b/fio.c
@@ -217,7 +217,7 @@ static int __check_min_rate(struct thread_data *td, struct timeval *now,
        if (mtime_since(&td->start, now) < 2000)
                return 0;
 
-       iops += td->io_blocks[ddir];
+       iops += td->this_io_blocks[ddir];
        bytes += td->this_io_bytes[ddir];
        ratemin += td->o.ratemin[ddir];
        rate_iops += td->o.rate_iops[ddir];
@@ -986,6 +986,8 @@ static void reset_io_counters(struct thread_data *td)
 {
        td->stat_io_bytes[0] = td->stat_io_bytes[1] = 0;
        td->this_io_bytes[0] = td->this_io_bytes[1] = 0;
+       td->stat_io_blocks[0] = td->stat_io_blocks[1] = 0;
+       td->this_io_blocks[0] = td->this_io_blocks[1] = 0;
        td->zone_bytes = 0;
        td->rate_bytes[0] = td->rate_bytes[1] = 0;
        td->rate_blocks[0] = td->rate_blocks[1] = 0;
@@ -1184,12 +1186,12 @@ static void *thread_main(void *data)
        clear_state = 0;
        while (keep_running(td)) {
                fio_gettime(&td->start, NULL);
-               memcpy(&td->stat_sample_time[0], &td->start, sizeof(td->start));
-               memcpy(&td->stat_sample_time[1], &td->start, sizeof(td->start));
+               memcpy(&td->bw_sample_time, &td->start, sizeof(td->start));
+               memcpy(&td->iops_sample_time, &td->start, sizeof(td->start));
                memcpy(&td->tv_cache, &td->start, sizeof(td->start));
 
                if (td->o.ratemin[0] || td->o.ratemin[1])
-                       memcpy(&td->lastrate, &td->stat_sample_time,
+                       memcpy(&td->lastrate, &td->bw_sample_time,
                                                        sizeof(td->lastrate));
 
                if (clear_state)
@@ -1266,6 +1268,14 @@ static void *thread_main(void *data)
                } else
                        finish_log(td, td->clat_log, "clat");
        }
+       if (td->iops_log) {
+               if (td->o.iops_log_file) {
+                       finish_log_named(td, td->iops_log,
+                                               td->o.iops_log_file, "iops");
+               } else
+                       finish_log(td, td->iops_log, "iops");
+       }
+
        fio_mutex_up(writeout_mutex);
        if (td->o.exec_postrun)
                exec_string(td->o.exec_postrun);

diff --git a/fio.h b/fio.h
index ab0d6a49f63b453224a854925405373895d24e33..65f79e03ee2f0f88789bd1329e0c046650de9168 100644 (file)
--- a/fio.h
+++ b/fio.h
@@ -139,6 +139,7 @@ struct thread_options {
        unsigned int use_os_rand;
        unsigned int write_lat_log;
        unsigned int write_bw_log;
+       unsigned int write_iops_log;
        unsigned int norandommap;
        unsigned int softrandommap;
        unsigned int bs_unaligned;
@@ -157,6 +158,7 @@ struct thread_options {
        unsigned long long ramp_time;
        unsigned int overwrite;
        unsigned int bw_avg_time;
+       unsigned int iops_avg_time;
        unsigned int loops;
        unsigned long long zone_size;
        unsigned long long zone_skip;
@@ -203,6 +205,7 @@ struct thread_options {
        char *write_iolog_file;
        char *bw_log_file;
        char *lat_log_file;
+       char *iops_log_file;
        char *replay_redirect;
 
        /*
@@ -265,9 +268,13 @@ struct thread_data {
        struct io_log *clat_log;
        struct io_log *lat_log;
        struct io_log *bw_log;
+       struct io_log *iops_log;
 
        uint64_t stat_io_bytes[2];
-       struct timeval stat_sample_time[2];
+       struct timeval bw_sample_time;
+
+       uint64_t stat_io_blocks[2];
+       struct timeval iops_sample_time;
 
        struct rusage ru_start;
        struct rusage ru_end;
@@ -365,6 +372,7 @@ struct thread_data {
 
        unsigned long io_issues[2];
        unsigned long long io_blocks[2];
+       unsigned long long this_io_blocks[2];
        unsigned long long io_bytes[2];
        unsigned long long io_skip_bytes;
        unsigned long long this_io_bytes[2];

diff --git a/fio_generate_plots b/fio_generate_plots
index 21d7c6a9a2fd77f8731146b2434f0a1947dc1382..4285415eac2879da04850369a6aab7a067c5518f 100755 (executable)
--- a/fio_generate_plots
+++ b/fio_generate_plots
@@ -42,6 +42,24 @@ if [ "$PLOT_LINE"x != "x" ]; then
        echo "set title 'Bandwidth - $TITLE'; set xlabel 'time (msec)'; set ylabel 'KB/sec'; set terminal png size $XRES,$YRES; set output '$TITLE-bw.png'; plot " $PLOT_LINE | $GNUPLOT -
 fi
 
+PLOT_LINE=""
+for i in *iops.log; do
+       if [ ! -r $i ]; then
+               continue
+       fi
+       PT=$(echo $i | sed s/_iops.log//g)
+       if [ "$PLOT_LINE"x != "x" ]; then
+               PLOT_LINE=$PLOT_LINE", "
+       fi
+
+       PLOT_LINE=$PLOT_LINE"'$i' title '$PT' with lines"
+done
+
+if [ "$PLOT_LINE"x != "x" ]; then
+       echo Making bw logs
+       echo "set title 'IOPS - $TITLE'; set xlabel 'time (msec)'; set ylabel 'IOPS'; set terminal png size $XRES,$YRES; set output '$TITLE-IOPS.png'; plot " $PLOT_LINE | $GNUPLOT -
+fi
+
 PLOT_LINE=""
 for i in *slat.log; do
        if [ ! -r $i ]; then

diff --git a/init.c b/init.c
index fcee02bb918d649eb751aa1ad1fadd993cb4d263..94b417e438c3ca257e9cac1312086b9909d6140a 100644 (file)
--- a/init.c
+++ b/init.c
@@ -768,6 +768,8 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num)
        }
        if (td->o.write_bw_log)
                setup_log(&td->bw_log);
+       if (td->o.write_iops_log)
+               setup_log(&td->iops_log);
 
        if (!td->o.name)
                td->o.name = strdup(jobname);

diff --git a/io_u.c b/io_u.c
index 77069c55277f8aeb0cd93d99754b12913cdfbaee..9488adeeffe43983a03a0b8089eb400afe7db96c 100644 (file)
--- a/io_u.c
+++ b/io_u.c
@@ -13,6 +13,7 @@
 
 struct io_completion_data {
        int nr;                         /* input */
+       int account;                    /* input */
 
        int error;                      /* output */
        unsigned long bytes_done[2];    /* output */
@@ -1266,6 +1267,36 @@ void io_u_log_error(struct thread_data *td, struct io_u *io_u)
                td_verror(td, io_u->error, "io_u error");
 }
 
+static void account_io_completion(struct thread_data *td, struct io_u *io_u,
+                                 struct io_completion_data *icd,
+                                 const enum fio_ddir idx, unsigned int bytes)
+{
+       unsigned long uninitialized_var(lusec);
+
+       if (!icd->account)
+               return;
+
+       if (!td->o.disable_clat || !td->o.disable_bw)
+               lusec = utime_since(&io_u->issue_time, &icd->time);
+
+       if (!td->o.disable_lat) {
+               unsigned long tusec;
+
+               tusec = utime_since(&io_u->start_time, &icd->time);
+               add_lat_sample(td, idx, tusec, bytes);
+       }
+
+       if (!td->o.disable_clat) {
+               add_clat_sample(td, idx, lusec, bytes);
+               io_u_mark_latency(td, lusec);
+       }
+
+       if (!td->o.disable_bw)
+               add_bw_sample(td, idx, bytes, &icd->time);
+
+       add_iops_sample(td, idx, &icd->time);
+}
+
 static void io_completed(struct thread_data *td, struct io_u *io_u,
                         struct io_completion_data *icd)
 {
@@ -1303,6 +1334,7 @@ static void io_completed(struct thread_data *td, struct io_u *io_u,
                int ret;
 
                td->io_blocks[idx]++;
+               td->this_io_blocks[idx]++;
                td->io_bytes[idx] += bytes;
                td->this_io_bytes[idx] += bytes;
 
@@ -1318,25 +1350,9 @@ static void io_completed(struct thread_data *td, struct io_u *io_u,
                        }
                }
 
-               if (ramp_time_over(td)) {
-                       unsigned long uninitialized_var(lusec);
+               if (ramp_time_over(td) && td->runstate == TD_RUNNING) {
+                       account_io_completion(td, io_u, icd, idx, bytes);
 
-                       if (!td->o.disable_clat || !td->o.disable_bw)
-                               lusec = utime_since(&io_u->issue_time,
-                                                       &icd->time);
-                       if (!td->o.disable_lat) {
-                               unsigned long tusec;
-
-                               tusec = utime_since(&io_u->start_time,
-                                                       &icd->time);
-                               add_lat_sample(td, idx, tusec, bytes);
-                       }
-                       if (!td->o.disable_clat) {
-                               add_clat_sample(td, idx, lusec, bytes);
-                               io_u_mark_latency(td, lusec);
-                       }
-                       if (!td->o.disable_bw)
-                               add_bw_sample(td, idx, bytes, &icd->time);
                        if (__should_check_rate(td, idx)) {
                                td->rate_pending_usleep[idx] =
                                        ((td->this_io_bytes[idx] *
@@ -1386,6 +1402,7 @@ static void init_icd(struct thread_data *td, struct io_completion_data *icd,
                fio_gettime(&icd->time, NULL);
 
        icd->nr = nr;
+       icd->account = 1;
 
        icd->error = 0;
        icd->bytes_done[0] = icd->bytes_done[1] = 0;
@@ -1404,6 +1421,8 @@ static void ios_completed(struct thread_data *td,
 
                if (!(io_u->flags & IO_U_F_FREE_DEF))
                        put_io_u(td, io_u);
+
+               icd->account = 0;
        }
 }
 

diff --git a/iolog.h b/iolog.h
index dd4d6470d85173794b48f943284df0a3e748e173..d8140f28c2f8a59de00bc32731edefc7d720cf97 100644 (file)
--- a/iolog.h
+++ b/iolog.h
@@ -93,6 +93,7 @@ extern void add_slat_sample(struct thread_data *, enum fio_ddir, unsigned long,
                                unsigned int);
 extern void add_bw_sample(struct thread_data *, enum fio_ddir, unsigned int,
                                struct timeval *);
+extern void add_iops_sample(struct thread_data *, enum fio_ddir, struct timeval *);
 extern void show_run_stats(void);
 extern void init_disk_util(struct thread_data *);
 extern void update_rusage_stat(struct thread_data *);

diff --git a/options.c b/options.c
index 1914037583fb24163936e18aac7b4473aed87728..f07cc7c42aedcee338fb5e9a7b7a7bbf773f4998 100644 (file)
--- a/options.c
+++ b/options.c
@@ -749,6 +749,17 @@ static int str_write_lat_log_cb(void *data, const char *str)
        return 0;
 }
 
+static int str_write_iops_log_cb(void *data, const char *str)
+{
+       struct thread_data *td = data;
+
+       if (str)
+               td->o.iops_log_file = strdup(str);
+
+       td->o.write_iops_log = 1;
+       return 0;
+}
+
 static int str_gtod_reduce_cb(void *data, int *il)
 {
        struct thread_data *td = data;
@@ -1821,6 +1832,15 @@ static struct fio_option options[FIO_MAX_OPTS] = {
                .help   = "Time window over which to calculate bandwidth"
                          " (msec)",
                .def    = "500",
+               .parent = "write_bw_log",
+       },
+       {
+               .name   = "iopsavgtime",
+               .type   = FIO_OPT_INT,
+               .off1   = td_var_offset(iops_avg_time),
+               .help   = "Time window over which to calculate IOPS (msec)",
+               .def    = "500",
+               .parent = "write_iops_log",
        },
        {
                .name   = "create_serialize",
@@ -1938,6 +1958,13 @@ static struct fio_option options[FIO_MAX_OPTS] = {
                .cb     = str_write_lat_log_cb,
                .help   = "Write log of latency during run",
        },
+       {
+               .name   = "write_iops_log",
+               .type   = FIO_OPT_STR,
+               .off1   = td_var_offset(write_iops_log),
+               .cb     = str_write_iops_log_cb,
+               .help   = "Write log of IOPS during run",
+       },
        {
                .name   = "hugepage-size",
                .type   = FIO_OPT_INT,

diff --git a/stat.c b/stat.c
index 7bcae310f8d41bb388abc1af6b773b6125ea0492..6c652d6e4f8708039c7074d833471d3e0ddd0c0b 100644 (file)
--- a/stat.c
+++ b/stat.c
@@ -372,7 +372,7 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts,
                double p_of_agg;
 
                p_of_agg = mean * 100 / (double) rs->agg[ddir];
-               log_info("    bw (KB/s) : min=%5lu, max=%5lu, per=%3.2f%%,"
+               log_info("     bw (KB/s) : min=%5lu, max=%5lu, per=%3.2f%%,"
                         " avg=%5.02f, stdev=%5.02f\n", min, max, p_of_agg,
                                                        mean, dev);
        }
@@ -1004,7 +1004,7 @@ void add_bw_sample(struct thread_data *td, enum fio_ddir ddir, unsigned int bs,
        if (!ddir_rw(ddir))
                return;
 
-       spent = mtime_since(&td->stat_sample_time[ddir], t);
+       spent = mtime_since(&td->bw_sample_time, t);
        if (spent < td->o.bw_avg_time)
                return;
 
@@ -1015,6 +1015,32 @@ void add_bw_sample(struct thread_data *td, enum fio_ddir ddir, unsigned int bs,
        if (td->bw_log)
                add_log_sample(td, td->bw_log, rate, ddir, bs);
 
-       fio_gettime(&td->stat_sample_time[ddir], NULL);
+       fio_gettime(&td->bw_sample_time, NULL);
        td->stat_io_bytes[ddir] = td->this_io_bytes[ddir];
 }
+
+void add_iops_sample(struct thread_data *td, enum fio_ddir ddir,
+                    struct timeval *t)
+{
+       struct thread_stat *ts = &td->ts;
+       unsigned long spent, iops;
+
+       if (!ddir_rw(ddir))
+               return;
+
+       spent = mtime_since(&td->iops_sample_time, t);
+       if (spent < td->o.iops_avg_time)
+               return;
+
+       iops = ((td->this_io_blocks[ddir] - td->stat_io_blocks[ddir]) * 1000) / spent;
+
+       add_stat_sample(&ts->iops_stat[ddir], iops);
+
+       if (td->iops_log) {
+               assert(iops);
+               add_log_sample(td, td->iops_log, iops, ddir, 0);
+       }
+
+       fio_gettime(&td->iops_sample_time, NULL);
+       td->stat_io_blocks[ddir] = td->this_io_blocks[ddir];
+}

diff --git a/stat.h b/stat.h
index 89766fc0d3e8bf0ab0d01e7f7f5e7ae72b842855..68bc97022563ecefb92629d0d06f16478e0f967a 100644 (file)
--- a/stat.h
+++ b/stat.h
@@ -128,6 +128,7 @@ struct thread_stat {
        struct io_stat slat_stat[2];            /* submission latency */
        struct io_stat lat_stat[2];             /* total latency */
        struct io_stat bw_stat[2];              /* bandwidth stats */
+       struct io_stat iops_stat[2];            /* IOPS stats */
 
        /*
         * fio system usage accounting