Reduce LOG_MSEC_SLACK
authorJeff Furlong <jeff.furlong@wdc.com>
Wed, 7 Mar 2018 00:53:20 +0000 (17:53 -0700)
committerJens Axboe <axboe@kernel.dk>
Wed, 7 Mar 2018 00:53:20 +0000 (17:53 -0700)
Starting in fio 2.99, there is an odd problem when --ramp_time is used
with --write_iops_log.  The reported IOPs for the first ~200s or so are
artificially inflated by fio, always monotonically increasing until
about 200s, then resets to normal.  With fio 2.99, disabling --ramp_time
avoids the issue.  And, with fio 2.21, using --ramp_time and
--write_iops_log does not create the problem.  Consider a job:

fio --name=test --ioengine=libaio --direct=1 --rw=randread --iodepth=1 \\
--size=100% --bs=4k --filename=/dev/nvme1n1 --runtime=300s \\
--ramp_time=10s --write_iops_log=test --log_avg_msec=1000

See the attached plot for fio induced IOPs during the first ~200s.
Using a longer runtime makes identifying the issue easier if the DUT is
consistently performing.

One simple method to resolve this inflation is by reducing the
LOG_MSEC_SLACK from 10 milliseconds to 1 millisecond, given that we now
operate some time structures to the nanosecond level (so 10ms of slack
seems excessive).  Below I also fixup some data type issues to match
existing types (avoids typecasts or potential compiler warnings).

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

diff --git a/stat.c b/stat.c
index 5bbc056fbeda1b38137002ad37ea5f135c52eeab..f89913ba3b8a057e9fef4ff061d72ad4c006479d 100644 (file)
--- a/stat.c
+++ b/stat.c
@@ -18,7 +18,7 @@
 #include "helper_thread.h"
 #include "smalloc.h"
 
-#define LOG_MSEC_SLACK 10
+#define LOG_MSEC_SLACK 1
 
 struct fio_mutex *stat_mutex;
 
@@ -2340,9 +2340,11 @@ static void _add_stat_to_log(struct io_log *iolog, unsigned long elapsed,
                __add_stat_to_log(iolog, ddir, elapsed, log_max);
 }
 
-static long add_log_sample(struct thread_data *td, struct io_log *iolog,
-                          union io_sample_data data, enum fio_ddir ddir,
-                          unsigned int bs, uint64_t offset)
+static unsigned long add_log_sample(struct thread_data *td,
+                                   struct io_log *iolog,
+                                   union io_sample_data data,
+                                   enum fio_ddir ddir, unsigned int bs,
+                                   uint64_t offset)
 {
        unsigned long elapsed, this_window;
 
@@ -2373,7 +2375,7 @@ static long add_log_sample(struct thread_data *td, struct io_log *iolog,
        if (elapsed < iolog->avg_last[ddir])
                return iolog->avg_last[ddir] - elapsed;
        else if (this_window < iolog->avg_msec) {
-               int diff = iolog->avg_msec - this_window;
+               unsigned long diff = iolog->avg_msec - this_window;
 
                if (inline_log(iolog) || diff > LOG_MSEC_SLACK)
                        return diff;
@@ -2562,7 +2564,7 @@ static int __add_samples(struct thread_data *td, struct timespec *parent_tv,
 {
        unsigned long spent, rate;
        enum fio_ddir ddir;
-       unsigned int next, next_log;
+       unsigned long next, next_log;
 
        next_log = avg_time;