From b8bc8cba9512c6dce4891fda86de675053605ca2 Mon Sep 17 00:00:00 2001 From: Jens Axboe Date: Thu, 1 Dec 2011 09:04:31 +0100 Subject: [PATCH] Add log_avg_msec option By default, fio will note an entry in the bw/iops/lat logs for every IO that is completed. This quickly eats up a lot of disk space for long running jobs. By setting this option to eg 1000, fio will average the results logged over 1 second instead. This reduces the resolution of the log, but makes it more manageable. Signed-off-by: Jens Axboe --- HOWTO | 12 ++++++++++++ fio.1 | 7 +++++++ fio.c | 4 ++-- fio.h | 1 + init.c | 10 +++++----- iolog.c | 4 +++- iolog.h | 13 ++++++++++++- options.c | 7 +++++++ stat.c | 37 ++++++++++++++++++++++++++++++++++++- 9 files changed, 85 insertions(+), 10 deletions(-) diff --git a/HOWTO b/HOWTO index ac7e729c..c6304a7c 100644 --- a/HOWTO +++ b/HOWTO @@ -1101,6 +1101,18 @@ write_lat_log=str Same as write_bw_log, except that this option stores io write_bw_log=str If given, write an IOPS log of the jobs in this job file. See write_bw_log. +write_iops_log=str Same as write_bw_log, but writes IOPS. If no filename is + given with this option, the default filename of + "jobname_type.log" is used. Even if the filename is given, + fio will still append the type of log. + +log_avg_msec=int By default, fio will log an entry in the iops, latency, + or bw log for every IO that completes. When writing to the + disk log, that can quickly grow to a very large size. Setting + this option makes fio average the each log entry over the + specified period of time, reducing the resolution of the log. + Defaults to 0. + lockmem=int Pin down the specified amount of memory with mlock(2). Can potentially be used instead of removing memory or booting with less memory to simulate a smaller amount of memory. diff --git a/fio.1 b/fio.1 index 138208f2..aeba39a3 100644 --- a/fio.1 +++ b/fio.1 @@ -872,6 +872,13 @@ Same as \fBwrite_bw_log\fR, but writes IOPS. If no filename is given with this option, the default filename of "jobname_type.log" is used. Even if the filename is given, fio will still append the type of log. .TP +.BI log_avg_msec \fR=\fPint +By default, fio will log an entry in the iops, latency, or bw log for every +IO that completes. When writing to the disk log, that can quickly grow to a +very large size. Setting this option makes fio average the each log entry +over the specified period of time, reducing the resolution of the log. +Defaults to 0. +.TP .BI disable_lat \fR=\fPbool Disable measurements of total latency numbers. Useful only for cutting back the number of calls to gettimeofday, as that does impact performance at diff --git a/fio.c b/fio.c index ce29c26b..77e5572b 100644 --- a/fio.c +++ b/fio.c @@ -1797,8 +1797,8 @@ int exec_run(void) return 0; if (write_bw_log) { - setup_log(&agg_io_log[DDIR_READ]); - setup_log(&agg_io_log[DDIR_WRITE]); + setup_log(&agg_io_log[DDIR_READ], 0); + setup_log(&agg_io_log[DDIR_WRITE], 0); } startup_mutex = fio_mutex_init(0); diff --git a/fio.h b/fio.h index 47339909..afffb9aa 100644 --- a/fio.h +++ b/fio.h @@ -147,6 +147,7 @@ struct thread_options { unsigned int write_lat_log; unsigned int write_bw_log; unsigned int write_iops_log; + unsigned int log_avg_msec; unsigned int norandommap; unsigned int softrandommap; unsigned int bs_unaligned; diff --git a/init.c b/init.c index 482ce099..381bb654 100644 --- a/init.c +++ b/init.c @@ -832,14 +832,14 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num) goto err; if (td->o.write_lat_log) { - setup_log(&td->lat_log); - setup_log(&td->slat_log); - setup_log(&td->clat_log); + setup_log(&td->lat_log, td->o.log_avg_msec); + setup_log(&td->slat_log, td->o.log_avg_msec); + setup_log(&td->clat_log, td->o.log_avg_msec); } if (td->o.write_bw_log) - setup_log(&td->bw_log); + setup_log(&td->bw_log, td->o.log_avg_msec); if (td->o.write_iops_log) - setup_log(&td->iops_log); + setup_log(&td->iops_log, td->o.log_avg_msec); if (!td->o.name) td->o.name = strdup(jobname); diff --git a/iolog.c b/iolog.c index f962864d..1d61ba23 100644 --- a/iolog.c +++ b/iolog.c @@ -492,13 +492,15 @@ int init_iolog(struct thread_data *td) return ret; } -void setup_log(struct io_log **log) +void setup_log(struct io_log **log, unsigned long avg_msec) { struct io_log *l = malloc(sizeof(*l)); + memset(l, 0, sizeof(*l)); l->nr_samples = 0; l->max_samples = 1024; l->log = malloc(l->max_samples * sizeof(struct io_sample)); + l->avg_msec = avg_msec; *log = l; } diff --git a/iolog.h b/iolog.h index 53bb66ca..95617fcc 100644 --- a/iolog.h +++ b/iolog.h @@ -29,9 +29,20 @@ struct io_sample { * Dynamically growing data sample log */ struct io_log { + /* + * Entries already logged + */ unsigned long nr_samples; unsigned long max_samples; struct io_sample *log; + + /* + * Windowed average, for logging single entries average over some + * period of time. + */ + struct io_stat avg_window[2]; + unsigned long avg_msec; + unsigned long avg_last; }; enum { @@ -97,7 +108,7 @@ extern void add_iops_sample(struct thread_data *, enum fio_ddir, struct timeval extern void init_disk_util(struct thread_data *); extern void update_rusage_stat(struct thread_data *); extern void update_io_ticks(void); -extern void setup_log(struct io_log **); +extern void setup_log(struct io_log **, unsigned long); extern void finish_log(struct thread_data *, struct io_log *, const char *); extern void finish_log_named(struct thread_data *, struct io_log *, const char *, const char *); extern void __finish_log(struct io_log *, const char *); diff --git a/options.c b/options.c index 2e1e709e..f9bd1a44 100644 --- a/options.c +++ b/options.c @@ -1950,6 +1950,13 @@ static struct fio_option options[FIO_MAX_OPTS] = { .cb = str_write_iops_log_cb, .help = "Write log of IOPS during run", }, + { + .name = "log_avg_msec", + .type = FIO_OPT_INT, + .off1 = td_var_offset(log_avg_msec), + .help = "Average bw/iops/lat logs over this period of time", + .def = "0", + }, { .name = "hugepage-size", .type = FIO_OPT_INT, diff --git a/stat.c b/stat.c index 2400cd70..7de23621 100644 --- a/stat.c +++ b/stat.c @@ -1128,6 +1128,9 @@ static void __add_log_sample(struct io_log *iolog, unsigned long val, { const int nr_samples = iolog->nr_samples; + if (!iolog->nr_samples) + iolog->avg_last = t; + if (iolog->nr_samples == iolog->max_samples) { int new_size = sizeof(struct io_sample) * iolog->max_samples*2; @@ -1146,10 +1149,42 @@ static void add_log_sample(struct thread_data *td, struct io_log *iolog, unsigned long val, enum fio_ddir ddir, unsigned int bs) { + unsigned long elapsed, this_window, mr, mw; + if (!ddir_rw(ddir)) return; - __add_log_sample(iolog, val, ddir, bs, mtime_since_now(&td->epoch)); + elapsed = mtime_since_now(&td->epoch); + + /* + * If no time averaging, just add the log sample. + */ + if (!iolog->avg_msec) { + __add_log_sample(iolog, val, ddir, bs, elapsed); + return; + } + + /* + * Add the sample. If the time period has passed, then + * add that entry to the log and clear. + */ + add_stat_sample(&iolog->avg_window[ddir], val); + + this_window = elapsed - iolog->avg_last; + if (this_window < iolog->avg_msec) + return; + + mr = iolog->avg_window[DDIR_READ].mean.u.f; + mw = iolog->avg_window[DDIR_WRITE].mean.u.f; + + if (mr) + __add_log_sample(iolog, mr, DDIR_READ, 0, elapsed); + if (mw) + __add_log_sample(iolog, mw, DDIR_WRITE, 0, elapsed); + + memset(&iolog->avg_window[DDIR_READ], 0, sizeof(struct io_stat)); + memset(&iolog->avg_window[DDIR_WRITE], 0, sizeof(struct io_stat)); + iolog->avg_last = elapsed; } void add_agg_sample(unsigned long val, enum fio_ddir ddir, unsigned int bs) -- 2.25.1