From: Jens Axboe <jens.axboe@oracle.com>
Date: Fri, 24 Nov 2006 12:12:56 +0000 (+0100)
Subject: [PATCH] Improve time accounting for a job
X-Git-Tag: fio-1.10~16
X-Git-Url: https://git.kernel.dk/?p=fio.git;a=commitdiff_plain;h=690089990d051d86b4ef2b6fd5c1972c0dd4897b;hp=08aae9a0d5f3d24152abd7515984439bbfd3c05d

[PATCH] Improve time accounting for a job

We need to account loop time in usecs, or the null io engine can
get the timing wrong. For the system usage stats, don't use summed
up loop counts, but calculate end-start time instead.

Signed-off-by: Jens Axboe <jens.axboe@oracle.com>
---

diff --git a/fio.c b/fio.c
index a175be7a..28864bdf 100644
--- a/fio.c
+++ b/fio.c
@@ -605,6 +605,7 @@ static void clear_io_state(struct thread_data *td)
  */
 static void *thread_main(void *data)
 {
+	unsigned long long runtime[2];
 	struct thread_data *td = data;
 
 	if (!td->use_thread)
@@ -658,11 +659,12 @@ static void *thread_main(void *data)
 	if (open_files(td))
 		goto err;
 
-	fio_gettime(&td->epoch, NULL);
-
 	if (td->exec_prerun)
 		system(td->exec_prerun);
 
+	fio_gettime(&td->epoch, NULL);
+
+	runtime[0] = runtime[1] = 0;
 	while (td->loops--) {
 		getrusage(RUSAGE_SELF, &td->ru_start);
 		fio_gettime(&td->start, NULL);
@@ -679,9 +681,9 @@ static void *thread_main(void *data)
 		else
 			do_io(td);
 
-		td->runtime[td->ddir] += mtime_since_now(&td->start);
+		runtime[td->ddir] += utime_since_now(&td->start);
 		if (td_rw(td) && td->io_bytes[td->ddir ^ 1])
-			td->runtime[td->ddir ^ 1] = td->runtime[td->ddir];
+			runtime[td->ddir ^ 1] = runtime[td->ddir];
 
 		update_rusage_stat(td);
 
@@ -696,12 +698,16 @@ static void *thread_main(void *data)
 
 		do_verify(td);
 
-		td->runtime[DDIR_READ] += mtime_since_now(&td->start);
+		runtime[DDIR_READ] += utime_since_now(&td->start);
 
 		if (td->error || td->terminate)
 			break;
 	}
 
+	fio_gettime(&td->end_time, NULL);
+	td->runtime[0] = runtime[0] / 1000;
+	td->runtime[1] = runtime[1] / 1000;
+
 	if (td->bw_log)
 		finish_log(td, td->bw_log, "bw");
 	if (td->slat_log)
diff --git a/fio.h b/fio.h
index cb78f255..791b005e 100644
--- a/fio.h
+++ b/fio.h
@@ -308,6 +308,7 @@ struct thread_data {
 
 	struct timeval start;	/* start of this loop */
 	struct timeval epoch;	/* time job was started */
+	struct timeval end_time;/* time job ended */
 
 	/*
 	 * fio system usage accounting
@@ -452,6 +453,7 @@ extern int setup_rate(struct thread_data *);
  * Time functions
  */
 extern unsigned long utime_since(struct timeval *, struct timeval *);
+extern unsigned long utime_since_now(struct timeval *);
 extern unsigned long mtime_since(struct timeval *, struct timeval *);
 extern unsigned long mtime_since_now(struct timeval *);
 extern unsigned long time_since_now(struct timeval *);
diff --git a/stat.c b/stat.c
index e6da4218..731b3036 100644
--- a/stat.c
+++ b/stat.c
@@ -258,9 +258,6 @@ void disk_util_timer_arm(void)
 
 void update_rusage_stat(struct thread_data *td)
 {
-	if (!(td->runtime[0] + td->runtime[1]))
-		return;
-
 	getrusage(RUSAGE_SELF, &td->ru_end);
 
 	td->usr_time += mtime_since(&td->ru_start.ru_utime, &td->ru_end.ru_utime);
@@ -362,6 +359,7 @@ static void show_thread_status(struct thread_data *td,
 			       struct group_run_stats *rs)
 {
 	double usr_cpu, sys_cpu;
+	unsigned long runtime;
 
 	if (!(td->io_bytes[0] + td->io_bytes[1]) && !td->error)
 		return;
@@ -372,8 +370,9 @@ static void show_thread_status(struct thread_data *td,
 	if (td->io_bytes[td->ddir ^ 1])
 		show_ddir_status(td, rs, td->ddir ^ 1);
 
-	if (td->runtime[0] + td->runtime[1]) {
-		double runt = td->runtime[0] + td->runtime[1];
+	runtime = mtime_since(&td->epoch, &td->end_time);
+	if (runtime) {
+		double runt = runtime;
 
 		usr_cpu = (double) td->usr_time * 100 / runt;
 		sys_cpu = (double) td->sys_time * 100 / runt;
diff --git a/time.c b/time.c
index cb44c209..6c9eb0a8 100644
--- a/time.c
+++ b/time.c
@@ -21,7 +21,7 @@ unsigned long utime_since(struct timeval *s, struct timeval *e)
 	return sec + usec;
 }
 
-static unsigned long utime_since_now(struct timeval *s)
+unsigned long utime_since_now(struct timeval *s)
 {
 	struct timeval t;