From f29b25a370598d387e539c3dcae126274c6cbf4d Mon Sep 17 00:00:00 2001 From: Jens Axboe Date: Mon, 23 Jul 2007 08:56:43 +0200 Subject: [PATCH] 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 --- filesetup.c | 29 ++++++- fio.c | 9 +- fio.h | 24 +++++- io_u.c | 4 +- ioengines.c | 4 + log.c | 233 ++++++++++++++++++++++++++++++++++++++++++++++++---- 6 files changed, 278 insertions(+), 25 deletions(-) diff --git a/filesetup.c b/filesetup.c index 93cddb1f..7a9a2afe 100644 --- 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]; @@ -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++; + + return cur_files; } 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); } } + +/* + * 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 6e0dae24..16e19c8f 100644 --- 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"); - 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); @@ -937,6 +935,13 @@ err: 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; diff --git a/fio.h b/fio.h index f2e69a7e..b7d8582e 100644 --- a/fio.h +++ b/fio.h @@ -35,6 +35,7 @@ enum fio_ddir { DDIR_READ = 0, DDIR_WRITE, DDIR_SYNC, + DDIR_INVAL = -1, }; enum td_ddir { @@ -85,11 +86,17 @@ struct io_piece { 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 delay; + union { + unsigned long delay; + unsigned int file_action; + }; }; #ifdef FIO_HAVE_SYSLET @@ -674,8 +681,15 @@ struct disk_util { /* * 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 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 *); @@ -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 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 int get_fileno(struct thread_data *, const char *); +extern void free_release_files(struct thread_data *); /* * ETA/status stuff diff --git a/io_u.c b/io_u.c index b636f576..309969a6 100644 --- 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 (td->o.write_iolog_file) - write_iolog_put(td, io_u); - + log_io_u(td, io_u); return 0; } diff --git a/ioengines.c b/ioengines.c index feb986a8..76e71b9e 100644 --- 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: + log_file(td, f, FIO_LOG_OPEN_FILE); 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) { + 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 */ diff --git a/log.c b/log.c index 5ed30eb6..07ba950b 100644 --- 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 #include +#include #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) @@ -30,6 +57,7 @@ int read_iolog_get(struct thread_data *td, struct io_u *io_u) { 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); @@ -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; + /* + * 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); @@ -120,25 +165,127 @@ void write_iolog_close(struct thread_data *td) 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; + int rw, reads, writes, fileno = 0, file_action = 0; /* stupid gcc */ + char *fname, *act; 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. @@ -173,7 +320,6 @@ static int init_iolog_read(struct thread_data *td) } free(str); - fclose(f); 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; + 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; } + /* + * 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"); @@ -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); + + /* + * 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; } -- 2.25.1