From: Jeff Furlong <jeff.furlong@wdc.com>
Date: Wed, 7 Mar 2018 00:53:20 +0000 (-0700)
Subject: Reduce LOG_MSEC_SLACK
X-Git-Tag: fio-3.6~55
X-Git-Url: https://git.kernel.dk/?p=fio.git;a=commitdiff_plain;h=674456bf7d0f775f774c8097c8bcb98b48cccc51

Reduce LOG_MSEC_SLACK

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

diff --git a/stat.c b/stat.c
index 5bbc056f..f89913ba 100644
--- 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;