From 3aea75b14510301a80744b417ac08840ccfcf5b3 Mon Sep 17 00:00:00 2001 From: Karl Cronburg Date: Thu, 18 Aug 2016 12:48:47 -0400 Subject: [PATCH] Option for changing log files to use Unix epoch instead of being zero-based (when fio starts) epoch. This makes it easier to analyze the data in the context of other benchmarking tools running at the same time as fio. Signed-off-by: Karl Cronburg --- HOWTO | 4 ++++ backend.c | 2 +- cconv.c | 2 ++ fio.1 | 5 +++++ fio.h | 1 + fio_time.h | 1 + libfio.c | 10 ++++------ options.c | 9 +++++++++ rate-submit.c | 2 +- stat.c | 2 +- thread_options.h | 3 +++ time.c | 11 +++++++++++ 12 files changed, 43 insertions(+), 9 deletions(-) diff --git a/HOWTO b/HOWTO index c1b768d2..07419a12 100644 --- a/HOWTO +++ b/HOWTO @@ -1681,6 +1681,10 @@ log_store_compressed=bool If set, fio will store the log files in a the --inflate-log command line parameter. The files will be stored with a .fz suffix. +log_unix_epoch=bool If set, fio will log Unix timestamps to the log + files produced by enabling write_type_log for each log type, instead + of the default zero-based timestamps. + block_error_percentiles=bool If set, record errors in trim block-sized units from writes and trims and output a histogram of how many trims it took to get to errors, and what kind diff --git a/backend.c b/backend.c index b43486dc..d9865860 100644 --- a/backend.c +++ b/backend.c @@ -1675,7 +1675,7 @@ static void *thread_main(void *data) if (rate_submit_init(td, sk_out)) goto err; - fio_gettime(&td->epoch, NULL); + set_epoch_time(td, o->log_unix_epoch); fio_getrusage(&td->ru_start); memcpy(&td->bw_sample_time, &td->epoch, sizeof(td->epoch)); memcpy(&td->iops_sample_time, &td->epoch, sizeof(td->epoch)); diff --git a/cconv.c b/cconv.c index 8d9a0a8e..194e342c 100644 --- a/cconv.c +++ b/cconv.c @@ -187,6 +187,7 @@ void convert_thread_options_to_cpu(struct thread_options *o, o->log_offset = le32_to_cpu(top->log_offset); o->log_gz = le32_to_cpu(top->log_gz); o->log_gz_store = le32_to_cpu(top->log_gz_store); + o->log_unix_epoch = le32_to_cpu(top->log_unix_epoch); o->norandommap = le32_to_cpu(top->norandommap); o->softrandommap = le32_to_cpu(top->softrandommap); o->bs_unaligned = le32_to_cpu(top->bs_unaligned); @@ -379,6 +380,7 @@ void convert_thread_options_to_net(struct thread_options_pack *top, top->log_offset = cpu_to_le32(o->log_offset); top->log_gz = cpu_to_le32(o->log_gz); top->log_gz_store = cpu_to_le32(o->log_gz_store); + top->log_unix_epoch = cpu_to_le32(o->log_unix_epoch); top->norandommap = cpu_to_le32(o->norandommap); top->softrandommap = cpu_to_le32(o->softrandommap); top->bs_unaligned = cpu_to_le32(o->bs_unaligned); diff --git a/fio.1 b/fio.1 index 696664af..8d596fb1 100644 --- a/fio.1 +++ b/fio.1 @@ -1546,6 +1546,11 @@ If set, fio will store the log files in a compressed format. They can be decompressed with fio, using the \fB\-\-inflate-log\fR command line parameter. The files will be stored with a \fB\.fz\fR suffix. .TP +.BI log_unix_epoch \fR=\fPbool +If set, fio will log Unix timestamps to the log files produced by enabling +\fBwrite_type_log\fR for each log type, instead of the default zero-based +timestamps. +.TP .BI block_error_percentiles \fR=\fPbool If set, record errors in trim block-sized units from writes and trims and output a histogram of how many trims it took to get to errors, and what kind of error diff --git a/fio.h b/fio.h index 0da0bc5d..80b9c358 100644 --- a/fio.h +++ b/fio.h @@ -311,6 +311,7 @@ struct thread_data { struct timeval start; /* start of this loop */ struct timeval epoch; /* time job was started */ + unsigned long long unix_epoch; /* Time job was started, unix epoch based. */ struct timeval last_issue; long time_offset; struct timeval tv_cache; diff --git a/fio_time.h b/fio_time.h index e31ea097..b49cc828 100644 --- a/fio_time.h +++ b/fio_time.h @@ -20,5 +20,6 @@ extern bool ramp_time_over(struct thread_data *); extern bool in_ramp_time(struct thread_data *); extern void fio_time_init(void); extern void timeval_add_msec(struct timeval *, unsigned int); +extern void set_epoch_time(struct thread_data *, int); #endif diff --git a/libfio.c b/libfio.c index fb7d35ae..d88ed4ed 100644 --- a/libfio.c +++ b/libfio.c @@ -134,7 +134,6 @@ void clear_io_state(struct thread_data *td, int all) void reset_all_stats(struct thread_data *td) { - struct timeval tv; int i; reset_io_counters(td, 1); @@ -148,11 +147,10 @@ void reset_all_stats(struct thread_data *td) td->rwmix_issues = 0; } - fio_gettime(&tv, NULL); - memcpy(&td->epoch, &tv, sizeof(tv)); - memcpy(&td->start, &tv, sizeof(tv)); - memcpy(&td->iops_sample_time, &tv, sizeof(tv)); - memcpy(&td->bw_sample_time, &tv, sizeof(tv)); + set_epoch_time(td, td->o.log_unix_epoch); + memcpy(&td->start, &td->epoch, sizeof(struct timeval)); + memcpy(&td->iops_sample_time, &td->epoch, sizeof(struct timeval)); + memcpy(&td->bw_sample_time, &td->epoch, sizeof(struct timeval)); lat_target_reset(td); clear_rusage_stat(td); diff --git a/options.c b/options.c index 517ee68a..50b4d09e 100644 --- a/options.c +++ b/options.c @@ -3647,6 +3647,15 @@ struct fio_option fio_options[FIO_MAX_OPTS] = { .help = "Install libz-dev(el) to get compression support", }, #endif + { + .name = "log_unix_epoch", + .lname = "Log epoch unix", + .type = FIO_OPT_BOOL, + .off1 = offsetof(struct thread_options, log_unix_epoch), + .help = "Use Unix time in log files", + .category = FIO_OPT_C_LOG, + .group = FIO_OPT_G_INVALID, + }, { .name = "block_error_percentiles", .lname = "Block error percentiles", diff --git a/rate-submit.c b/rate-submit.c index 2efbdcba..42927ffe 100644 --- a/rate-submit.c +++ b/rate-submit.c @@ -123,7 +123,7 @@ static int io_workqueue_init_worker_fn(struct submit_worker *sw) if (td_io_init(td)) goto err_io_init; - fio_gettime(&td->epoch, NULL); + set_epoch_time(td, td->o.log_unix_epoch); fio_getrusage(&td->ru_start); clear_io_state(td, 1); diff --git a/stat.c b/stat.c index 5e7c593f..552d88dd 100644 --- a/stat.c +++ b/stat.c @@ -2020,7 +2020,7 @@ static void __add_log_sample(struct io_log *iolog, unsigned long val, s = get_sample(iolog, cur_log, cur_log->nr_samples); s->val = val; - s->time = t; + s->time = t + iolog->td->unix_epoch; io_sample_set_ddir(iolog, s, ddir); s->bs = bs; diff --git a/thread_options.h b/thread_options.h index d70fda3f..1b4590f7 100644 --- a/thread_options.h +++ b/thread_options.h @@ -135,6 +135,7 @@ struct thread_options { unsigned int log_offset; unsigned int log_gz; unsigned int log_gz_store; + unsigned int log_unix_epoch; unsigned int norandommap; unsigned int softrandommap; unsigned int bs_unaligned; @@ -393,11 +394,13 @@ struct thread_options_pack { uint32_t log_offset; uint32_t log_gz; uint32_t log_gz_store; + uint32_t log_unix_epoch; uint32_t norandommap; uint32_t softrandommap; uint32_t bs_unaligned; uint32_t fsync_on_close; uint32_t bs_is_seq_rand; + uint32_t pad1; uint32_t random_distribution; uint32_t exitall_error; diff --git a/time.c b/time.c index f1c5d3fe..f5dc0496 100644 --- a/time.c +++ b/time.c @@ -151,6 +151,17 @@ void set_genesis_time(void) fio_gettime(&genesis, NULL); } +void set_epoch_time(struct thread_data *td, int log_unix_epoch) +{ + fio_gettime(&td->epoch, NULL); + if (log_unix_epoch) { + struct timeval tv; + gettimeofday(&tv, NULL); + td->unix_epoch = (unsigned long long)(tv.tv_sec) * 1000 + + (unsigned long long)(tv.tv_usec) / 1000; + } +} + void fill_start_time(struct timeval *t) { memcpy(t, &genesis, sizeof(genesis)); -- 2.25.1