From: Jens Axboe <axboe@kernel.dk>
Date: Wed, 5 Oct 2011 12:07:07 +0000 (+0200)
Subject: Fix for hosed end-of-run log numbers
X-Git-Tag: fio-1.99.5~6^2~2
X-Git-Url: https://git.kernel.dk/?p=fio.git;a=commitdiff_plain;h=5f03ff75ff84cd473ae7060415d5f85039f07ab7

Fix for hosed end-of-run log numbers

For queued IO workloads, we complete the pending count in one
go at the end of the run. But the completion time isn't updated,
so we end up getting a lot of tail log entries that are identical
if the timing is against us.

Fix this by only accounting the first of the last batch of ios.

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

diff --git a/io_u.c b/io_u.c
index 77069c55..0bc83d22 100644
--- 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,34 @@ 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);
+}
+
 static void io_completed(struct thread_data *td, struct io_u *io_u,
 			 struct io_completion_data *icd)
 {
@@ -1319,24 +1348,8 @@ static void io_completed(struct thread_data *td, struct io_u *io_u,
 		}
 
 		if (ramp_time_over(td)) {
-			unsigned long uninitialized_var(lusec);
+			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 +1399,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 +1418,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;
 	}
 }