X-Git-Url: https://git.kernel.dk/?p=fio.git;a=blobdiff_plain;f=log.c;h=1ac2e35345b91a4e691c66d0f68924adc609b428;hp=039e74b25e77c5098631b83d1e0fbf16b26b0e27;hb=03e20d687566753b90383571e5e152c5142bdffd;hpb=59b9ddfc30c9ff38dfbd071eafe295d9ffdd5f25 diff --git a/log.c b/log.c index 039e74b2..1ac2e353 100644 --- a/log.c +++ b/log.c @@ -4,22 +4,34 @@ */ #include #include +#include #include -#include "list.h" +#include "flist.h" #include "fio.h" +#include "verify.h" +#include "trim.h" static const char iolog_ver2[] = "fio version 2 iolog"; +void queue_io_piece(struct thread_data *td, struct io_piece *ipo) +{ + flist_add_tail(&ipo->list, &td->io_log_list); + td->total_io_size += ipo->len; +} + void log_io_u(struct thread_data *td, struct io_u *io_u) { - const char *act[] = { "read", "write", "sync" }; + const char *act[] = { "read", "write", "sync", "datasync", + "sync_file_range", "wait", "trim" }; - assert(io_u->ddir < 3); + assert(io_u->ddir <= 6); 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); + 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, @@ -32,6 +44,13 @@ void log_file(struct thread_data *td, struct fio_file *f, if (!td->o.write_iolog_file) return; + + /* + * this happens on the pre-open/close done before the job starts + */ + if (!td->iolog_f) + return; + fprintf(td->iolog_f, "%s %s\n", f->file_name, act[what]); } @@ -53,42 +72,82 @@ static void iolog_delay(struct thread_data *td, unsigned long delay) usec_sleep(td, delay); } -int read_iolog_get(struct thread_data *td, struct io_u *io_u) +static int ipo_special(struct thread_data *td, struct io_piece *ipo) { - struct io_piece *ipo; + struct fio_file *f; + int ret; - while (!list_empty(&td->io_log_list)) { - ipo = list_entry(td->io_log_list.next, struct io_piece, list); - list_del(&ipo->list); + /* + * Not a special ipo + */ + if (ipo->ddir != DDIR_INVAL) + return 0; - /* - * invalid ddir, this is a file action - */ - if (ipo->ddir == DDIR_INVAL) { - struct fio_file *f = &td->files[ipo->fileno]; + f = td->files[ipo->fileno]; + + switch (ipo->file_action) { + case FIO_LOG_OPEN_FILE: + ret = td_io_open_file(td, f); + if (!ret) + break; + td_verror(td, ret, "iolog open file"); + return -1; + case FIO_LOG_CLOSE_FILE: + td_io_close_file(td, f); + break; + case FIO_LOG_UNLINK_FILE: + unlink(f->file_name); + break; + default: + log_err("fio: bad file action %d\n", ipo->file_action); + break; + } - if (ipo->file_action == FIO_LOG_OPEN_FILE) { - assert(!td_io_open_file(td, f)); - free(ipo); - continue; - } else if (ipo->file_action == FIO_LOG_CLOSE_FILE) { - td_io_close_file(td, f); - free(ipo); - continue; - } + return 1; +} + +int read_iolog_get(struct thread_data *td, struct io_u *io_u) +{ + struct io_piece *ipo; + unsigned long elapsed; + + while (!flist_empty(&td->io_log_list)) { + int ret; + + ipo = flist_entry(td->io_log_list.next, struct io_piece, list); + flist_del(&ipo->list); + remove_trim_entry(td, ipo); + + ret = ipo_special(td, ipo); + if (ret < 0) { + free(ipo); + break; + } else if (ret > 0) { + free(ipo); + continue; } - io_u->offset = ipo->offset; - io_u->buflen = ipo->len; io_u->ddir = ipo->ddir; - io_u->file = &td->files[ipo->fileno]; - get_file(io_u->file); - - if (ipo->delay) - iolog_delay(td, ipo->delay); + if (ipo->ddir != DDIR_WAIT) { + io_u->offset = ipo->offset; + io_u->buflen = ipo->len; + io_u->file = td->files[ipo->fileno]; + get_file(io_u->file); + dprint(FD_IO, "iolog: get %llu/%lu/%s\n", io_u->offset, + io_u->buflen, io_u->file->file_name); + if (ipo->delay) + iolog_delay(td, ipo->delay); + } else { + elapsed = mtime_since_genesis(); + if (ipo->delay > elapsed) + usec_sleep(td, (ipo->delay - elapsed) * 1000); + + } free(ipo); - return 0; + + if (io_u->ddir != DDIR_WAIT) + return 0; } td->done = 1; @@ -103,6 +162,16 @@ void prune_io_piece_log(struct thread_data *td) while ((n = rb_first(&td->io_hist_tree)) != NULL) { ipo = rb_entry(n, struct io_piece, rb_node); rb_erase(n, &td->io_hist_tree); + remove_trim_entry(td, ipo); + td->io_hist_len--; + free(ipo); + } + + while (!flist_empty(&td->io_hist_list)) { + ipo = flist_entry(td->io_hist_list.next, struct io_piece, list); + flist_del(&ipo->list); + remove_trim_entry(td, ipo); + td->io_hist_len--; free(ipo); } } @@ -116,10 +185,16 @@ void log_io_piece(struct thread_data *td, struct io_u *io_u) struct io_piece *ipo, *__ipo; ipo = malloc(sizeof(struct io_piece)); + init_ipo(ipo); ipo->file = io_u->file; ipo->offset = io_u->offset; ipo->len = io_u->buflen; + if (io_u_should_trim(td, io_u)) { + flist_add_tail(&ipo->trim_list, &td->trim_list); + td->trim_entries++; + } + /* * We don't need to sort the entries, if: * @@ -128,33 +203,55 @@ void log_io_piece(struct thread_data *td, struct io_u *io_u) * * For both these cases, just reading back data in the order we * wrote it out is the fastest. + * + * One exception is if we don't have a random map AND we are doing + * verifies, in that case we need to check for duplicate blocks and + * drop the old one, which we rely on the rb insert/lookup for + * handling. */ - if (!td_random(td) || !td->o.overwrite || - (io_u->file->flags & FIO_FILE_NOSORT)) { - INIT_LIST_HEAD(&ipo->list); - list_add_tail(&ipo->list, &td->io_hist_list); + if ((!td_random(td) || !td->o.overwrite) && + (file_randommap(td, ipo->file) || td->o.verify == VERIFY_NONE)) { + INIT_FLIST_HEAD(&ipo->list); + flist_add_tail(&ipo->list, &td->io_hist_list); + ipo->flags |= IP_F_ONLIST; + td->io_hist_len++; return; } RB_CLEAR_NODE(&ipo->rb_node); - p = &td->io_hist_tree.rb_node; - parent = NULL; /* * Sort the entry into the verification list */ +restart: + p = &td->io_hist_tree.rb_node; + parent = NULL; while (*p) { parent = *p; __ipo = rb_entry(parent, struct io_piece, rb_node); - if (ipo->offset <= __ipo->offset) + if (ipo->file < __ipo->file) p = &(*p)->rb_left; - else + else if (ipo->file > __ipo->file) + p = &(*p)->rb_right; + else if (ipo->offset < __ipo->offset) + p = &(*p)->rb_left; + else if (ipo->offset > __ipo->offset) p = &(*p)->rb_right; + else { + assert(ipo->len == __ipo->len); + td->io_hist_len--; + rb_erase(parent, &td->io_hist_tree); + remove_trim_entry(td, __ipo); + free(__ipo); + goto restart; + } } rb_link_node(&ipo->rb_node, parent, p); rb_insert_color(&ipo->rb_node, &td->io_hist_tree); + ipo->flags |= IP_F_ONRB; + td->io_hist_len++; } void write_iolog_close(struct thread_data *td) @@ -174,7 +271,7 @@ static int read_iolog2(struct thread_data *td, FILE *f) { unsigned long long offset; unsigned int bytes; - int reads, writes, fileno = 0, file_action = 0; /* stupid gcc */ + int reads, writes, waits, fileno = 0, file_action = 0; /* stupid gcc */ char *fname, *act; char *str, *p; enum fio_ddir rw; @@ -189,24 +286,32 @@ static int read_iolog2(struct thread_data *td, FILE *f) fname = malloc(256+16); act = malloc(256+16); - reads = writes = 0; + reads = writes = waits = 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); + r = sscanf(p, "%256s %256s %llu %u", fname, act, &offset, + &bytes); if (r == 4) { /* * Check action first */ - if (!strcmp(act, "read")) + if (!strcmp(act, "wait")) + rw = DDIR_WAIT; + else if (!strcmp(act, "read")) rw = DDIR_READ; else if (!strcmp(act, "write")) rw = DDIR_WRITE; else if (!strcmp(act, "sync")) rw = DDIR_SYNC; + else if (!strcmp(act, "datasync")) + rw = DDIR_DATASYNC; + else if (!strcmp(act, "trim")) + rw = DDIR_TRIM; else { - log_err("fio: bad iolog file action: %s\n",act); + log_err("fio: bad iolog file action: %s\n", + act); continue; } } else if (r == 2) { @@ -223,24 +328,28 @@ static int read_iolog2(struct thread_data *td, FILE *f) fileno = get_fileno(td, fname); file_action = FIO_LOG_CLOSE_FILE; } else { - log_err("fio: bad iolog file action: %s\n",act); + 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++; /* * Don't add a write for ro mode */ if (read_only) continue; - } else if (rw != DDIR_SYNC && rw != DDIR_INVAL) { + writes++; + } else if (rw == DDIR_WAIT) { + waits++; + } else if (rw == DDIR_INVAL) { + } else if (!ddir_sync(rw)) { log_err("bad ddir: %d\n", rw); continue; } @@ -249,19 +358,20 @@ static int read_iolog2(struct thread_data *td, FILE *f) * Make note of file */ ipo = malloc(sizeof(*ipo)); - memset(ipo, 0, sizeof(*ipo)); - INIT_LIST_HEAD(&ipo->list); - ipo->offset = offset; - ipo->len = bytes; + init_ipo(ipo); ipo->ddir = rw; - if (bytes > td->o.max_bs[rw]) - td->o.max_bs[rw] = bytes; - if (rw == DDIR_INVAL) { + if (rw == DDIR_WAIT) { + ipo->delay = offset; + } else { + ipo->offset = offset; + ipo->len = bytes; + if (bytes > td->o.max_bs[rw]) + td->o.max_bs[rw] = bytes; ipo->fileno = fileno; ipo->file_action = file_action; } - list_add_tail(&ipo->list, &td->io_log_list); - td->total_io_size += bytes; + + queue_io_piece(td, ipo); } free(str); @@ -269,80 +379,12 @@ static int read_iolog2(struct thread_data *td, FILE *f) free(fname); if (writes && read_only) { - log_err("fio: <%s> skips replay of %d writes due to read-only\n", td->o.name, writes); + log_err("fio: <%s> skips replay of %d writes due to" + " read-only\n", td->o.name, writes); writes = 0; } - 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 reads, writes; - int rw; - - /* - * Read in the read iolog and store it, reuse the infrastructure - * for doing verifications. - */ - str = malloc(4096); - reads = writes = 0; - while ((p = fgets(str, 4096, f)) != NULL) { - struct io_piece *ipo; - - if (sscanf(p, "%d,%llu,%u", &rw, &offset, &bytes) != 3) { - log_err("bad iolog: %s\n", p); - continue; - } - if (rw == DDIR_READ) - reads++; - else if (rw == DDIR_WRITE) { - writes++; - /* - * Don't add a write for ro mode - */ - if (read_only) - continue; - } else if (rw != DDIR_SYNC) { - log_err("bad ddir: %d\n", rw); - continue; - } - - 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; - list_add_tail(&ipo->list, &td->io_log_list); - td->total_io_size += bytes; - } - - free(str); - - if (writes && read_only) { - log_err("fio: <%s> skips replay of %d writes due to read-only\n", td->o.name, writes); - writes = 0; - } - - if (!reads && !writes) + if (!reads && !writes && !waits) return 1; else if (reads && !writes) td->o.td_ddir = TD_DDIR_READ; @@ -383,16 +425,8 @@ static int init_iolog_read(struct thread_data *td) 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); + log_err("fio: iolog version 1 is no longer supported\n"); + ret = 1; } fclose(f); @@ -400,7 +434,7 @@ static int init_iolog_read(struct thread_data *td) } /* - * Setup a log for storing io patterns. + * Set up a log for storing io patterns. */ static int init_iolog_write(struct thread_data *td) { @@ -408,7 +442,7 @@ static int init_iolog_write(struct thread_data *td) FILE *f; unsigned int i; - f = fopen(td->o.write_iolog_file, "w+"); + f = fopen(td->o.write_iolog_file, "a"); if (!f) { perror("fopen write iolog"); return 1; @@ -442,9 +476,6 @@ int init_iolog(struct thread_data *td) { int ret = 0; - if (td->io_ops->flags & FIO_DISKLESSIO) - return 0; - if (td->o.read_iolog_file) { /* * Check if it's a blktrace file and load that if possible. @@ -475,24 +506,35 @@ void __finish_log(struct io_log *log, const char *name) unsigned int i; FILE *f; - f = fopen(name, "w"); + f = fopen(name, "a"); if (!f) { perror("fopen log"); return; } - for (i = 0; i < log->nr_samples; i++) - fprintf(f, "%lu, %lu, %u\n", log->log[i].time, log->log[i].val, log->log[i].ddir); + for (i = 0; i < log->nr_samples; i++) { + fprintf(f, "%lu, %lu, %u, %u\n", log->log[i].time, + log->log[i].val, + log->log[i].ddir, + log->log[i].bs); + } fclose(f); free(log->log); free(log); } -void finish_log(struct thread_data *td, struct io_log *log, const char *name) +void finish_log_named(struct thread_data *td, struct io_log *log, + const char *prefix, const char *postfix) { - char file_name[256]; + char file_name[256], *p; - snprintf(file_name, 200, "client%d_%s.log", td->thread_number, name); - __finish_log(log, file_name); + snprintf(file_name, 200, "%s_%s.log", prefix, postfix); + p = basename(file_name); + __finish_log(log, p); +} + +void finish_log(struct thread_data *td, struct io_log *log, const char *name) +{ + finish_log_named(td, log, td->o.name, name); }