Add version 2 of the iolog format

The old format had some short comings - notably not supporting > 1
file workloads. So add a new format that defines adding/open/close
of files. Fio will still load the older format iologs, but the new
ones wont work on older fio versions.

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

diff --git a/filesetup.c b/filesetup.c
index 93cddb1f467b3aea77cfc3b858c1164e89da8964..7a9a2afed29b34d345e1628156c2d3ac6848163c 100644 (file)
--- a/filesetup.c
+++ b/filesetup.c
@@ -513,7 +513,7 @@ static void get_file_type(struct fio_file *f)
        }
 }
 
        }
 }
 

-void add_file(struct thread_data *td, const char *fname)
+int add_file(struct thread_data *td, const char *fname)

 {
        int cur_files = td->files_index;
        char file_name[PATH_MAX];
 {
        int cur_files = td->files_index;
        char file_name[PATH_MAX];


@@ -543,6 +543,8 @@ void add_file(struct thread_data *td, const char *fname)
        td->files_index++;
        if (f->filetype == FIO_TYPE_FILE)
                td->nr_normal_files++;
        td->files_index++;
        if (f->filetype == FIO_TYPE_FILE)
                td->nr_normal_files++;

+
+       return cur_files;

 }
 
 void get_file(struct fio_file *f)
 }
 
 void get_file(struct fio_file *f)


@@ -645,3 +647,28 @@ void dup_files(struct thread_data *td, struct thread_data *org)
                        f->file_name = strdup(f->file_name);
        }
 }
                        f->file_name = strdup(f->file_name);
        }
 }

+
+/*
+ * Returns the index that matches the filename, or -1 if not there
+ */
+int get_fileno(struct thread_data *td, const char *fname)
+{
+       struct fio_file *f;
+       unsigned int i;
+
+       for_each_file(td, f, i)
+               if (!strcmp(f->file_name, fname))
+                       return i;
+
+       return -1;
+}
+
+/*
+ * For log usage, where we add/open/close files automatically
+ */
+void free_release_files(struct thread_data *td)
+{
+       close_files(td);
+       td->files_index = 0;
+       td->nr_normal_files = 0;
+}

diff --git a/fio.c b/fio.c
index 6e0dae24d5cf0e8410c0b04e2d25856b7839b8b2..16e19c8fa8e080511c6e07c96691c809e8955b0a 100644 (file)
--- a/fio.c
+++ b/fio.c
@@ -921,8 +921,6 @@ static void *thread_main(void *data)
                finish_log(td, td->ts.slat_log, "slat");
        if (td->ts.clat_log)
                finish_log(td, td->ts.clat_log, "clat");
                finish_log(td, td->ts.slat_log, "slat");
        if (td->ts.clat_log)
                finish_log(td, td->ts.clat_log, "clat");

-       if (td->o.write_iolog_file)
-               write_iolog_close(td);

        if (td->o.exec_postrun) {
                if (system(td->o.exec_postrun) < 0)
                        log_err("fio: postrun %s failed\n", td->o.exec_postrun);
        if (td->o.exec_postrun) {
                if (system(td->o.exec_postrun) < 0)
                        log_err("fio: postrun %s failed\n", td->o.exec_postrun);


@@ -937,6 +935,13 @@ err:
        close_files(td);
        close_ioengine(td);
        cleanup_io_u(td);
        close_files(td);
        close_ioengine(td);
        cleanup_io_u(td);

+
+       /*
+        * do this very late, it will log file closing as well
+        */
+       if (td->o.write_iolog_file)
+               write_iolog_close(td);
+

        options_mem_free(td);
        td_set_runstate(td, TD_EXITED);
        return (void *) (unsigned long) td->error;
        options_mem_free(td);
        td_set_runstate(td, TD_EXITED);
        return (void *) (unsigned long) td->error;

diff --git a/fio.h b/fio.h
index f2e69a7e17fcd31a5bf3c05a2da2c494af82e7a6..b7d8582ebdcba3fc1c7b6a3c99e2b434cabbd8ed 100644 (file)
--- a/fio.h
+++ b/fio.h
@@ -35,6 +35,7 @@ enum fio_ddir {
        DDIR_READ = 0,
        DDIR_WRITE,
        DDIR_SYNC,
        DDIR_READ = 0,
        DDIR_WRITE,
        DDIR_SYNC,

+       DDIR_INVAL = -1,

 };
 
 enum td_ddir {
 };
 
 enum td_ddir {


@@ -85,11 +86,17 @@ struct io_piece {
                struct rb_node rb_node;
                struct list_head list;
        };
                struct rb_node rb_node;
                struct list_head list;
        };

-       struct fio_file *file;
+       union {
+               int fileno;
+               struct fio_file *file;
+       };

        unsigned long long offset;
        unsigned long len;
        enum fio_ddir ddir;
        unsigned long long offset;
        unsigned long len;
        enum fio_ddir ddir;

-       unsigned long delay;
+       union {
+               unsigned long delay;
+               unsigned int file_action;
+       };

 };
 
 #ifdef FIO_HAVE_SYSLET
 };
 
 #ifdef FIO_HAVE_SYSLET


@@ -674,8 +681,15 @@ struct disk_util {
 /*
  * Log exports
  */
 /*
  * Log exports
  */

+enum file_log_act {
+       FIO_LOG_ADD_FILE,
+       FIO_LOG_OPEN_FILE,
+       FIO_LOG_CLOSE_FILE,
+};
+

 extern int __must_check read_iolog_get(struct thread_data *, struct io_u *);
 extern int __must_check read_iolog_get(struct thread_data *, struct io_u *);

-extern void write_iolog_put(struct thread_data *, struct io_u *);
+extern void log_io_u(struct thread_data *, struct io_u *);
+extern void log_file(struct thread_data *, struct fio_file *, enum file_log_act);

 extern int __must_check init_iolog(struct thread_data *td);
 extern void log_io_piece(struct thread_data *, struct io_u *);
 extern void prune_io_piece_log(struct thread_data *);
 extern int __must_check init_iolog(struct thread_data *td);
 extern void log_io_piece(struct thread_data *, struct io_u *);
 extern void prune_io_piece_log(struct thread_data *);


@@ -738,12 +752,14 @@ extern int __must_check open_files(struct thread_data *);
 extern int __must_check file_invalidate_cache(struct thread_data *, struct fio_file *);
 extern int __must_check generic_open_file(struct thread_data *, struct fio_file *);
 extern void generic_close_file(struct thread_data *, struct fio_file *);
 extern int __must_check file_invalidate_cache(struct thread_data *, struct fio_file *);
 extern int __must_check generic_open_file(struct thread_data *, struct fio_file *);
 extern void generic_close_file(struct thread_data *, struct fio_file *);

-extern void add_file(struct thread_data *, const char *);
+extern int add_file(struct thread_data *, const char *);

 extern void get_file(struct fio_file *);
 extern void put_file(struct thread_data *, struct fio_file *);
 extern int add_dir_files(struct thread_data *, const char *);
 extern int init_random_map(struct thread_data *);
 extern void dup_files(struct thread_data *, struct thread_data *);
 extern void get_file(struct fio_file *);
 extern void put_file(struct thread_data *, struct fio_file *);
 extern int add_dir_files(struct thread_data *, const char *);
 extern int init_random_map(struct thread_data *);
 extern void dup_files(struct thread_data *, struct thread_data *);

+extern int get_fileno(struct thread_data *, const char *);
+extern void free_release_files(struct thread_data *);

 
 /*
  * ETA/status stuff
 
 /*
  * ETA/status stuff

diff --git a/io_u.c b/io_u.c
index b636f576eb808caa286eef42c3e3e7bc68bc8d8a..309969a6c2164d8e274fd2b31eac5ade246166d4 100644 (file)
--- a/io_u.c
+++ b/io_u.c
@@ -357,9 +357,7 @@ static int fill_io_u(struct thread_data *td, struct io_u *io_u)
         * If using a write iolog, store this entry.
         */
 out:
         * If using a write iolog, store this entry.
         */
 out:

-       if (td->o.write_iolog_file)
-               write_iolog_put(td, io_u);
-
+       log_io_u(td, io_u);

        return 0;
 }
 
        return 0;
 }
 

diff --git a/ioengines.c b/ioengines.c
index feb986a844bba2342c5844094bacc89f6ed26821..76e71b9ee4ef1e6cf3c2c23ebc8d036c8d98b04e 100644 (file)
--- a/ioengines.c
+++ b/ioengines.c
@@ -309,6 +309,7 @@ int td_io_open_file(struct thread_data *td, struct fio_file *f)
                memset(f->file_map, 0, f->num_maps * sizeof(long));
 
 done:
                memset(f->file_map, 0, f->num_maps * sizeof(long));
 
 done:

+       log_file(td, f, FIO_LOG_OPEN_FILE);

        td->nr_open_files++;
        get_file(f);
        return 0;
        td->nr_open_files++;
        get_file(f);
        return 0;


@@ -320,6 +321,9 @@ err:
 
 void td_io_close_file(struct thread_data *td, struct fio_file *f)
 {
 
 void td_io_close_file(struct thread_data *td, struct fio_file *f)
 {

+       if (!(f->flags & FIO_FILE_CLOSING))
+               log_file(td, f, FIO_LOG_CLOSE_FILE);
+

        /*
         * mark as closing, do real close when last io on it has completed
         */
        /*
         * mark as closing, do real close when last io on it has completed
         */

diff --git a/log.c b/log.c
index 5ed30eb6f103efb8ed6150d04a807a9dc018ef63..07ba950b9e147a5dfa98c7264fcebf660a5546d0 100644 (file)
--- a/log.c
+++ b/log.c
@@ -1,11 +1,38 @@
+/*
+ * Code related to writing an iolog of what a thread is doing, and to
+ * later read that back and replay
+ */

 #include <stdio.h>
 #include <stdlib.h>
 #include <stdio.h>
 #include <stdlib.h>

+#include <assert.h>

 #include "list.h"
 #include "fio.h"
 
 #include "list.h"
 #include "fio.h"
 

-void write_iolog_put(struct thread_data *td, struct io_u *io_u)
+static const char iolog_ver2[] = "fio version 2 iolog";
+
+void log_io_u(struct thread_data *td, struct io_u *io_u)

 {
 {

-       fprintf(td->iolog_f, "%u,%llu,%lu\n", io_u->ddir, io_u->offset, io_u->buflen);
+       const char *act[] = { "read", "write", "sync" };
+
+       assert(io_u->ddir < 3);
+
+       if (!td->o.write_iolog_file)
+               return;
+
+       fprintf(td->iolog_f, "%s %s %llu %lu\n", io_u->file->file_name, act[io_u->ddir], io_u->offset, io_u->buflen);
+}
+
+void log_file(struct thread_data *td, struct fio_file *f,
+             enum file_log_act what)
+{
+       const char *act[] = { "add", "open", "close" };
+
+       assert(what < 3);
+
+       if (!td->o.write_iolog_file)
+               return;
+
+       fprintf(td->iolog_f, "%s %s\n", f->file_name, act[what]);

 }
 
 static void iolog_delay(struct thread_data *td, unsigned long delay)
 }
 
 static void iolog_delay(struct thread_data *td, unsigned long delay)


@@ -30,6 +57,7 @@ int read_iolog_get(struct thread_data *td, struct io_u *io_u)
 {
        struct io_piece *ipo;
 
 {
        struct io_piece *ipo;
 

+restart:

        if (!list_empty(&td->io_log_list)) {
                ipo = list_entry(td->io_log_list.next, struct io_piece, list);
                list_del(&ipo->list);
        if (!list_empty(&td->io_log_list)) {
                ipo = list_entry(td->io_log_list.next, struct io_piece, list);
                list_del(&ipo->list);


@@ -38,6 +66,23 @@ int read_iolog_get(struct thread_data *td, struct io_u *io_u)
                io_u->ddir = ipo->ddir;
                io_u->file = ipo->file;
 
                io_u->ddir = ipo->ddir;
                io_u->file = ipo->file;
 

+               /*
+                * invalid ddir, this is a file action
+                */
+               if (io_u->ddir == DDIR_INVAL) {
+                       struct fio_file *f = &td->files[ipo->fileno];
+
+                       if (ipo->file_action == FIO_LOG_OPEN_FILE) {
+                               assert(!td_io_open_file(td, f));
+                               free(ipo);
+                               goto restart;
+                       } else if (ipo->file_action == FIO_LOG_CLOSE_FILE) {
+                               td_io_close_file(td, f);
+                               free(ipo);
+                               goto restart;
+                       }
+               }
+

                if (ipo->delay)
                        iolog_delay(td, ipo->delay);
 
                if (ipo->delay)
                        iolog_delay(td, ipo->delay);
 


@@ -120,25 +165,127 @@ void write_iolog_close(struct thread_data *td)
        fflush(td->iolog_f);
        fclose(td->iolog_f);
        free(td->iolog_buf);
        fflush(td->iolog_f);
        fclose(td->iolog_f);
        free(td->iolog_buf);

+       td->iolog_f = NULL;
+       td->iolog_buf = NULL;

 }
 
 /*
 }
 
 /*

- * Open a stored log and read in the entries.
+ * Read version 2 iolog data. It is enhanced to include per-file logging,
+ * syncs, etc.

  */
  */

-static int init_iolog_read(struct thread_data *td)
+static int read_iolog2(struct thread_data *td, FILE *f)

 {
        unsigned long long offset;
        unsigned int bytes;
 {
        unsigned long long offset;
        unsigned int bytes;

+       int rw, reads, writes, fileno = 0, file_action = 0; /* stupid gcc */
+       char *fname, *act;

        char *str, *p;
        char *str, *p;

-       FILE *f;
-       int rw, reads, writes;

 
 

-       f = fopen(td->o.read_iolog_file, "r");
-       if (!f) {
-               perror("fopen read iolog");
-               return 1;
+       free_release_files(td);
+
+       /*
+        * Read in the read iolog and store it, reuse the infrastructure
+        * for doing verifications.
+        */
+       str = malloc(4096);
+       fname = malloc(256+16);
+       act = malloc(256+16);
+
+       reads = writes = 0;
+       while ((p = fgets(str, 4096, f)) != NULL) {
+               struct io_piece *ipo;
+               int r;
+
+               r = sscanf(p, "%256s %256s %llu %u", fname, act, &offset, &bytes);
+               if (r == 4) {
+                       /*
+                        * Check action first
+                        */
+                       if (!strcmp(act, "read"))
+                               rw = DDIR_READ;
+                       else if (!strcmp(act, "write"))
+                               rw = DDIR_WRITE;
+                       else if (!strcmp(act, "sync"))
+                               rw = DDIR_SYNC;
+                       else {
+                               log_err("fio: bad iolog file action: %s\n",act);
+                               continue;
+                       }
+               } else if (r == 2) {
+                       rw = DDIR_INVAL;
+                       if (!strcmp(act, "add")) {
+                               td->o.nr_files++;
+                               fileno = add_file(td, fname);
+                               file_action = FIO_LOG_ADD_FILE;
+                               continue;
+                       } else if (!strcmp(act, "open")) {
+                               fileno = get_fileno(td, fname);
+                               file_action = FIO_LOG_OPEN_FILE;
+                       } else if (!strcmp(act, "close")) {
+                               fileno = get_fileno(td, fname);
+                               file_action = FIO_LOG_CLOSE_FILE;
+                       } else {
+                               log_err("fio: bad iolog file action: %s\n",act);
+                               continue;
+                       }
+               } else {
+                       log_err("bad iolog2: %s", p);
+                       continue;
+               }
+                       
+               if (rw == DDIR_READ)
+                       reads++;
+               else if (rw == DDIR_WRITE)
+                       writes++;
+               else if (rw != DDIR_SYNC && rw != DDIR_INVAL) {
+                       log_err("bad ddir: %d\n", rw);
+                       continue;
+               }
+
+               /*
+                * Make note of file
+                */
+               ipo = malloc(sizeof(*ipo));
+               memset(ipo, 0, sizeof(*ipo));
+               INIT_LIST_HEAD(&ipo->list);
+               ipo->offset = offset;
+               ipo->len = bytes;
+               ipo->ddir = (enum fio_ddir) rw;
+               if (bytes > td->o.max_bs[rw])
+                       td->o.max_bs[rw] = bytes;
+               if (rw == DDIR_INVAL) {
+                       ipo->fileno = fileno;
+                       ipo->file_action = file_action;
+               }
+               list_add_tail(&ipo->list, &td->io_log_list);

        }
 
        }
 

+       free(str);
+       free(act);
+       free(fname);
+
+       if (!reads && !writes)
+               return 1;
+       else if (reads && !writes)
+               td->o.td_ddir = TD_DDIR_READ;
+       else if (!reads && writes)
+               td->o.td_ddir = TD_DDIR_WRITE;
+       else
+               td->o.td_ddir = TD_DDIR_RW;
+
+       return 0;
+}
+
+/*
+ * Read version 1 iolog data.
+ */
+static int read_iolog(struct thread_data *td, FILE *f)
+{
+       unsigned long long offset;
+       unsigned int bytes;
+       char *str, *p;
+       int rw, reads, writes;
+

        /*
         * Read in the read iolog and store it, reuse the infrastructure
         * for doing verifications.
        /*
         * Read in the read iolog and store it, reuse the infrastructure
         * for doing verifications.


@@ -173,7 +320,6 @@ static int init_iolog_read(struct thread_data *td)
        }
 
        free(str);
        }
 
        free(str);

-       fclose(f);

 
        if (!reads && !writes)
                return 1;
 
        if (!reads && !writes)
                return 1;


@@ -188,17 +334,59 @@ static int init_iolog_read(struct thread_data *td)
 }
 
 /*
 }
 
 /*

- * Setup a log for storing io patterns.
+ * open iolog, check version, and call appropriate parser

  */
  */

-static int init_iolog_write(struct thread_data *td)
+static int init_iolog_read(struct thread_data *td)

 {
 {

+       char buffer[256], *p;

        FILE *f;
        FILE *f;

+       int ret;
+
+       f = fopen(td->o.read_iolog_file, "r");
+       if (!f) {
+               perror("fopen read iolog");
+               return 1;
+       }

 
 

-       if (td->o.nr_files > 1) {
-               log_err("fio: write_iolog only works with 1 file currently\n");
+       p = fgets(buffer, sizeof(buffer), f);
+       if (!p) {
+               td_verror(td, errno, "iolog read");
+               log_err("fio: unable to read iolog\n");

                return 1;
        }
 
                return 1;
        }
 

+       /*
+        * version 2 of the iolog stores a specific string as the
+        * first line, check for that
+        */
+       if (!strncmp(iolog_ver2, buffer, strlen(iolog_ver2)))
+               ret = read_iolog2(td, f);
+       else {
+               /*
+                * seek back to the beginning
+                */
+               if (fseek(f, 0, SEEK_SET) < 0) {
+                       td_verror(td, errno, "iolog read");
+                       log_err("fio: unable to read iolog\n");
+                       return 1;
+               }
+
+               ret = read_iolog(td, f);
+       }
+
+       fclose(f);
+       return ret;
+}
+
+/*
+ * Setup a log for storing io patterns.
+ */
+static int init_iolog_write(struct thread_data *td)
+{
+       struct fio_file *ff;
+       FILE *f;
+       unsigned int i;
+

        f = fopen(td->o.write_iolog_file, "w+");
        if (!f) {
                perror("fopen write iolog");
        f = fopen(td->o.write_iolog_file, "w+");
        if (!f) {
                perror("fopen write iolog");


@@ -211,6 +399,21 @@ static int init_iolog_write(struct thread_data *td)
        td->iolog_f = f;
        td->iolog_buf = malloc(8192);
        setvbuf(f, td->iolog_buf, _IOFBF, 8192);
        td->iolog_f = f;
        td->iolog_buf = malloc(8192);
        setvbuf(f, td->iolog_buf, _IOFBF, 8192);

+
+       /*
+        * write our version line
+        */
+       if (fprintf(f, "%s\n", iolog_ver2) < 0) {
+               perror("iolog init\n");
+               return 1;
+       }
+
+       /*
+        * add all known files
+        */
+       for_each_file(td, ff, i)
+               log_file(td, ff, FIO_LOG_ADD_FILE);
+

        return 0;
 }
 
        return 0;
 }