[PATCH] Time and seek optimizations
authorJens Axboe <jens.axboe@oracle.com>
Fri, 24 Nov 2006 09:42:00 +0000 (10:42 +0100)
committerJens Axboe <jens.axboe@oracle.com>
Fri, 24 Nov 2006 09:42:00 +0000 (10:42 +0100)
We did too many gettimeofday() calls, this patch cuts the number by
40%. Use clock_gettime() MONOTONIC instead, it is faster on my system
at least.

This patch also optimizes calling lseek() only when necessary for the
sync io engine.

Signed-off-by: Jens Axboe <jens.axboe@oracle.com>
13 files changed:
Makefile
Makefile.FreeBSD
Makefile.solaris
engines/fio-engine-sync.c
eta.c
filesetup.c
fio.c
fio.h
gettime.c [new file with mode: 0644]
io_u.c
ioengines.c
stat.c
time.c

index 07ec6a9..4a4434d 100644 (file)
--- a/Makefile
+++ b/Makefile
@@ -2,7 +2,7 @@ CC      = gcc
 CFLAGS = -W -Wwrite-strings -Wall -O2 -g -D_GNU_SOURCE -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64
 PROGS  = fio
 SCRIPTS = fio_generate_plots
-OBJS = fio.o ioengines.o init.o stat.o log.o time.o md5.o crc32.o \
+OBJS = gettime.o fio.o ioengines.o init.o stat.o log.o time.o md5.o crc32.o \
        filesetup.o eta.o verify.o memory.o io_u.o parse.o
 
 OBJS += engines/fio-engine-cpu.o
index 06cdc80..8947117 100644 (file)
@@ -2,8 +2,7 @@ CC      = gcc
 CFLAGS = -Wall -O2 -g -D_GNU_SOURCE -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64
 PROGS  = fio
 SCRIPTS = fio_generate_plots
-
-OBJS = fio.o ioengines.o init.o stat.o log.o time.o md5.o crc32.o \
+OBJS = gettime.o fio.o ioengines.o init.o stat.o log.o time.o md5.o crc32.o \
        filesetup.o eta.o verify.o memory.o io_u.o parse.o
 
 OBJS += engines/fio-engine-cpu.o
index 442a103..b487a05 100644 (file)
@@ -2,8 +2,7 @@ CC      = gcc
 CFLAGS = -Wall -O2 -g -D_GNU_SOURCE -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64
 PROGS  = fio
 SCRIPTS = fio_generate_plots
-
-OBJS = fio.o ioengines.o init.o stat.o log.o time.o md5.o crc32.o \
+OBJS = gettime.o fio.o ioengines.o init.o stat.o log.o time.o md5.o crc32.o \
        filesetup.o eta.o verify.o memory.o io_u.o parse.o
 
 OBJS += engines/fio-engine-cpu.o
index 5919830..c7ddd4c 100644 (file)
@@ -45,6 +45,8 @@ static int fio_syncio_prep(struct thread_data *td, struct io_u *io_u)
 
        if (io_u->ddir == DDIR_SYNC)
                return 0;
+       if (io_u->offset == f->last_completed_pos)
+               return 0;
 
        if (lseek(f->fd, io_u->offset, SEEK_SET) == -1) {
                td_verror(td, errno);
diff --git a/eta.c b/eta.c
index 339f656..99e59ec 100644 (file)
--- a/eta.c
+++ b/eta.c
@@ -238,7 +238,7 @@ void print_thread_status(void)
        if (mtime > 1000) {
                r_rate = (io_bytes[0] - prev_io_bytes[0]) / mtime;
                w_rate = (io_bytes[1] - prev_io_bytes[1]) / mtime;
-               gettimeofday(&prev_time, NULL);
+               fio_gettime(&prev_time, NULL);
                memcpy(prev_io_bytes, io_bytes, sizeof(io_bytes));
        }
 
index 50434e6..21854a9 100644 (file)
@@ -434,7 +434,8 @@ void close_files(struct thread_data *td)
        int i;
 
        for_each_file(td, f, i) {
-               if (td->unlink && td->filetype == FIO_TYPE_FILE) {
+               if (!td->filename && td->unlink &&
+                   td->filetype == FIO_TYPE_FILE) {
                        unlink(f->file_name);
                        free(f->file_name);
                        f->file_name = NULL;
diff --git a/fio.c b/fio.c
index 42ac0c9..a175be7 100644 (file)
--- a/fio.c
+++ b/fio.c
@@ -244,7 +244,6 @@ static int fio_io_sync(struct thread_data *td, struct fio_file *f)
  */
 void do_verify(struct thread_data *td)
 {
-       struct timeval t;
        struct io_u *io_u, *v_io_u = NULL;
        struct io_completion_data icd;
        struct fio_file *f;
@@ -265,14 +264,15 @@ void do_verify(struct thread_data *td)
                if (td->terminate)
                        break;
 
-               gettimeofday(&t, NULL);
-               if (runtime_exceeded(td, &t))
-                       break;
-
                io_u = __get_io_u(td);
                if (!io_u)
                        break;
 
+               if (runtime_exceeded(td, &io_u->start_time)) {
+                       put_io_u(td, io_u);
+                       break;
+               }
+
                if (get_next_verify(td, io_u)) {
                        put_io_u(td, io_u);
                        break;
@@ -313,6 +313,7 @@ void do_verify(struct thread_data *td)
                v_io_u = td->io_ops->event(td, 0);
                icd.nr = 1;
                icd.error = 0;
+               fio_gettime(&icd.time, NULL);
                io_completed(td, v_io_u, &icd);
 
                if (icd.error) {
@@ -349,7 +350,7 @@ static void do_cpuio(struct thread_data *td)
        int i = 0;
 
        while (!td->terminate) {
-               gettimeofday(&e, NULL);
+               fio_gettime(&e, NULL);
 
                if (runtime_exceeded(td, &e))
                        break;
@@ -370,7 +371,7 @@ static void do_cpuio(struct thread_data *td)
 static void do_io(struct thread_data *td)
 {
        struct io_completion_data icd;
-       struct timeval s, e;
+       struct timeval s;
        unsigned long usec;
        struct fio_file *f;
        int i, ret = 0;
@@ -432,19 +433,18 @@ static void do_io(struct thread_data *td)
                 * of completions except the very first one which may look
                 * a little bursty
                 */
-               gettimeofday(&e, NULL);
-               usec = utime_since(&s, &e);
+               usec = utime_since(&s, &icd.time);
 
                rate_throttle(td, usec, icd.bytes_done[td->ddir], td->ddir);
 
-               if (check_min_rate(td, &e)) {
+               if (check_min_rate(td, &icd.time)) {
                        if (exitall_on_terminate)
                                terminate_threads(td->groupid);
                        td_verror(td, ENOMEM);
                        break;
                }
 
-               if (runtime_exceeded(td, &e))
+               if (runtime_exceeded(td, &icd.time))
                        break;
 
                if (td->thinktime)
@@ -658,14 +658,14 @@ static void *thread_main(void *data)
        if (open_files(td))
                goto err;
 
-       gettimeofday(&td->epoch, NULL);
+       fio_gettime(&td->epoch, NULL);
 
        if (td->exec_prerun)
                system(td->exec_prerun);
 
        while (td->loops--) {
                getrusage(RUSAGE_SELF, &td->ru_start);
-               gettimeofday(&td->start, NULL);
+               fio_gettime(&td->start, NULL);
                memcpy(&td->stat_sample_time, &td->start, sizeof(td->start));
 
                if (td->ratemin)
@@ -692,7 +692,7 @@ static void *thread_main(void *data)
                        continue;
 
                clear_io_state(td);
-               gettimeofday(&td->start, NULL);
+               fio_gettime(&td->start, NULL);
 
                do_verify(td);
 
@@ -836,8 +836,6 @@ static void run_threads(void)
                }
        }
 
-       time_init();
-
        while (todo) {
                struct thread_data *map[MAX_JOBS];
                struct timeval this_start;
@@ -897,7 +895,7 @@ static void run_threads(void)
                 * Wait for the started threads to transition to
                 * TD_INITIALIZED.
                 */
-               gettimeofday(&this_start, NULL);
+               fio_gettime(&this_start, NULL);
                left = this_jobs;
                while (left) {
                        if (mtime_since_now(&this_start) > JOB_START_TIMEOUT)
diff --git a/fio.h b/fio.h
index faa06a4..cb78f25 100644 (file)
--- a/fio.h
+++ b/fio.h
@@ -156,6 +156,7 @@ struct fio_file {
        unsigned long long real_file_size;
        unsigned long long file_offset;
        unsigned long long last_pos;
+       unsigned long long last_completed_pos;
 
        unsigned long *file_map;
        unsigned int num_maps;
@@ -410,6 +411,7 @@ struct io_completion_data {
 
        int error;                      /* output */
        unsigned long bytes_done[2];    /* output */
+       struct timeval time;            /* output */
 };
 
 #define DISK_UTIL_MSEC (250)
@@ -436,7 +438,7 @@ extern void write_iolog_close(struct thread_data *);
  */
 extern void add_clat_sample(struct thread_data *, int, unsigned long);
 extern void add_slat_sample(struct thread_data *, int, unsigned long);
-extern void add_bw_sample(struct thread_data *, int);
+extern void add_bw_sample(struct thread_data *, int, struct timeval *);
 extern void show_run_stats(void);
 extern void init_disk_util(struct thread_data *);
 extern void update_rusage_stat(struct thread_data *);
@@ -449,7 +451,6 @@ extern int setup_rate(struct thread_data *);
 /*
  * Time functions
  */
-extern void time_init(void);
 extern unsigned long utime_since(struct timeval *, struct timeval *);
 extern unsigned long mtime_since(struct timeval *, struct timeval *);
 extern unsigned long mtime_since_now(struct timeval *);
@@ -459,6 +460,7 @@ extern void __usec_sleep(unsigned int);
 extern void usec_sleep(struct thread_data *, unsigned long);
 extern void rate_throttle(struct thread_data *, unsigned long, unsigned int, int);
 extern void fill_start_time(struct timeval *);
+extern void fio_gettime(struct timeval *, void *);
 
 /*
  * Init functions
diff --git a/gettime.c b/gettime.c
new file mode 100644 (file)
index 0000000..48aeb07
--- /dev/null
+++ b/gettime.c
@@ -0,0 +1,135 @@
+/*
+ * Memory helpers
+ */
+#include <unistd.h>
+#include <sys/time.h>
+
+#include "fio.h"
+#include "os.h"
+
+#include "hash.h"
+
+static int clock_gettime_works = 1;
+
+#ifdef FIO_DEBUG_TIME
+
+#define HASH_BITS      8
+#define HASH_SIZE      (1 << HASH_BITS)
+
+static struct list_head hash[HASH_SIZE];
+static int gtod_inited;
+
+struct gtod_log {
+       struct list_head list;
+       void *caller;
+       unsigned long calls;
+};
+
+static struct gtod_log *find_hash(void *caller)
+{
+       unsigned long h = hash_ptr(caller, HASH_BITS);
+       struct list_head *entry;
+
+       list_for_each(entry, &hash[h]) {
+               struct gtod_log *log = list_entry(entry, struct gtod_log, list);
+
+               if (log->caller == caller)
+                       return log;
+       }
+
+       return NULL;
+}
+
+static struct gtod_log *find_log(void *caller)
+{
+       struct gtod_log *log = find_hash(caller);
+
+       if (!log) {
+               unsigned long h;
+
+               log = malloc(sizeof(*log));
+               INIT_LIST_HEAD(&log->list);
+               log->caller = caller;
+               log->calls = 0;
+
+               h = hash_ptr(caller, HASH_BITS);
+               list_add_tail(&log->list, &hash[h]);
+       }
+
+       return log;
+}
+
+static void gtod_log_caller(void *caller)
+{
+       if (gtod_inited) {
+               struct gtod_log *log = find_log(caller);
+
+               log->calls++;
+       }
+}
+
+static void fio_exit fio_dump_gtod(void)
+{
+       unsigned long total_calls = 0;
+       int i;
+
+       for (i = 0; i < HASH_SIZE; i++) {
+               struct list_head *entry;
+               struct gtod_log *log;
+
+               list_for_each(entry, &hash[i]) {
+                       log = list_entry(entry, struct gtod_log, list);
+
+                       printf("function %p, calls %lu\n", log->caller, log->calls);
+                       total_calls += log->calls;
+               }
+       }
+
+       printf("Total %lu gettimeofday\n", total_calls);
+}
+
+static void fio_init gtod_init(void)
+{
+       int i;
+
+       for (i = 0; i < HASH_SIZE; i++)
+               INIT_LIST_HEAD(&hash[i]);
+
+       gtod_inited = 1;
+}
+
+#endif /* FIO_DEBUG_TIME */
+
+void fio_gettime(struct timeval *tp, void *caller)
+{
+#ifdef FIO_DEBUG_TIME
+       if (!caller)
+               caller = __builtin_return_address(0);
+
+       gtod_log_caller(caller);
+#else
+       caller = NULL;
+#endif
+repeat:
+       if (!clock_gettime_works)
+               gettimeofday(tp, NULL);
+       else {
+               struct timespec ts;
+
+               if (clock_gettime(CLOCK_MONOTONIC, &ts) < 0) {
+                       clock_gettime_works = 0;
+                       goto repeat;
+               }
+
+               tp->tv_sec = ts.tv_sec;
+               tp->tv_usec = ts.tv_nsec / 1000;
+       }
+}
+
+static void fio_init check_clock(void)
+{
+       struct timespec ts;
+
+       if (clock_getres(CLOCK_MONOTONIC, &ts) < 0)
+               clock_gettime_works = 0;
+}
diff --git a/io_u.c b/io_u.c
index 318614c..8ec9dd9 100644 (file)
--- a/io_u.c
+++ b/io_u.c
@@ -153,7 +153,7 @@ static int get_rw_ddir(struct thread_data *td)
                struct timeval now;
                unsigned long elapsed;
 
-               gettimeofday(&now, NULL);
+               fio_gettime(&now, NULL);
                elapsed = mtime_since_now(&td->rwmix_switch);
 
                /*
@@ -296,14 +296,13 @@ struct io_u *get_io_u(struct thread_data *td, struct fio_file *f)
                return NULL;
        }
 
-       gettimeofday(&io_u->start_time, NULL);
+       fio_gettime(&io_u->start_time, NULL);
        return io_u;
 }
 
 void io_completed(struct thread_data *td, struct io_u *io_u,
                  struct io_completion_data *icd)
 {
-       struct timeval e;
        unsigned long msec;
 
        if (io_u->ddir == DDIR_SYNC) {
@@ -313,8 +312,6 @@ void io_completed(struct thread_data *td, struct io_u *io_u,
 
        td->last_was_sync = 0;
 
-       gettimeofday(&e, NULL);
-
        if (!io_u->error) {
                unsigned int bytes = io_u->buflen - io_u->resid;
                const int idx = io_u->ddir;
@@ -324,10 +321,12 @@ void io_completed(struct thread_data *td, struct io_u *io_u,
                td->zone_bytes += bytes;
                td->this_io_bytes[idx] += bytes;
 
-               msec = mtime_since(&io_u->issue_time, &e);
+               io_u->file->last_completed_pos = io_u->offset + io_u->buflen;
+
+               msec = mtime_since(&io_u->issue_time, &icd->time);
 
                add_clat_sample(td, idx, msec);
-               add_bw_sample(td, idx);
+               add_bw_sample(td, idx, &icd->time);
 
                if ((td_rw(td) || td_write(td)) && idx == DDIR_WRITE)
                        log_io_piece(td, io_u);
@@ -342,6 +341,8 @@ void ios_completed(struct thread_data *td, struct io_completion_data *icd)
        struct io_u *io_u;
        int i;
 
+       fio_gettime(&icd->time, NULL);
+
        icd->error = 0;
        icd->bytes_done[0] = icd->bytes_done[1] = 0;
 
index 56a718c..1666612 100644 (file)
@@ -176,7 +176,7 @@ int td_io_getevents(struct thread_data *td, int min, int max,
 
 int td_io_queue(struct thread_data *td, struct io_u *io_u)
 {
-       gettimeofday(&io_u->issue_time, NULL);
+       fio_gettime(&io_u->issue_time, NULL);
 
        return td->io_ops->queue(td, io_u);
 }
diff --git a/stat.c b/stat.c
index 0ccf37e..e6da421 100644 (file)
--- a/stat.c
+++ b/stat.c
@@ -60,7 +60,7 @@ static void update_io_tick_disk(struct disk_util *du)
        dus->io_ticks += (__dus.io_ticks - ldus->io_ticks);
        dus->time_in_queue += (__dus.time_in_queue - ldus->time_in_queue);
 
-       gettimeofday(&t, NULL);
+       fio_gettime(&t, NULL);
        du->msec += mtime_since(&du->time, &t);
        memcpy(&du->time, &t, sizeof(t));
        memcpy(ldus, &__dus, sizeof(__dus));
@@ -102,7 +102,7 @@ static void disk_util_add(dev_t dev, char *path)
        du->name = strdup(basename(path));
        du->dev = dev;
 
-       gettimeofday(&du->time, NULL);
+       fio_gettime(&du->time, NULL);
        get_io_ticks(du, &du->last_dus);
 
        list_add_tail(&du->list, &disk_list);
@@ -574,9 +574,9 @@ void add_slat_sample(struct thread_data *td, int ddir, unsigned long msec)
                add_log_sample(td, td->slat_log, msec, ddir);
 }
 
-void add_bw_sample(struct thread_data *td, int ddir)
+void add_bw_sample(struct thread_data *td, int ddir, struct timeval *t)
 {
-       unsigned long spent = mtime_since_now(&td->stat_sample_time[ddir]);
+       unsigned long spent = mtime_since(&td->stat_sample_time[ddir], t);
        unsigned long rate;
 
        if (spent < td->bw_avg_time)
@@ -588,7 +588,7 @@ void add_bw_sample(struct thread_data *td, int ddir)
        if (td->bw_log)
                add_log_sample(td, td->bw_log, rate, ddir);
 
-       gettimeofday(&td->stat_sample_time[ddir], NULL);
+       fio_gettime(&td->stat_sample_time[ddir], NULL);
        td->stat_io_bytes[ddir] = td->this_io_bytes[ddir];
 }
 
diff --git a/time.c b/time.c
index d08c791..cb44c20 100644 (file)
--- a/time.c
+++ b/time.c
@@ -25,7 +25,7 @@ static unsigned long utime_since_now(struct timeval *s)
 {
        struct timeval t;
 
-       gettimeofday(&t, NULL);
+       fio_gettime(&t, NULL);
        return utime_since(s, &t);
 }
 
@@ -49,8 +49,9 @@ unsigned long mtime_since(struct timeval *s, struct timeval *e)
 unsigned long mtime_since_now(struct timeval *s)
 {
        struct timeval t;
+       void *p = __builtin_return_address(0);
 
-       gettimeofday(&t, NULL);
+       fio_gettime(&t, p);
        return mtime_since(s, &t);
 }
 
@@ -66,7 +67,7 @@ void __usec_sleep(unsigned int usec)
 {
        struct timeval start;
 
-       gettimeofday(&start, NULL);
+       fio_gettime(&start, NULL);
        while (utime_since_now(&start) < usec)
                nop;
 }
@@ -128,9 +129,9 @@ unsigned long mtime_since_genesis(void)
        return mtime_since_now(&genesis);
 }
 
-void time_init(void)
+static void fio_init time_init(void)
 {
-       gettimeofday(&genesis, NULL);
+       fio_gettime(&genesis, NULL);
 }
 
 void fill_start_time(struct timeval *t)