From d5b3cfd4064d5414c1bce4acc65c181db86a8634 Mon Sep 17 00:00:00 2001 From: aggieNick02 Date: Tue, 14 Dec 2021 13:56:58 -0600 Subject: [PATCH] Support for alternate epochs in fio log files Add options log_alternate_epoch and log_alternate_epoch_clock_id. This is similar to the log_unix_epoch option. This resolves the issue raised in Issue #1314 log_alternate_epoch, if true, causes log files to use the same epoch used used by the clock_id parameter to the unix clock_gettime function, where clock_id is specified by the log_alternate_epoch_clock_id option. This is particularly useful as it allows us to specify a clock id like CLOCK_MONOTONIC_RAW, which is natural for synchronizing log files between processes. The current log_unix_epoch is problematic for that purpose because that clock is not monotonic or continuous. It turns out that log_unix_epoch is actually equivalent to log_alternate_epoch with log_alternate_epoch_clock_id set to CLOCK_REALTIME=0. Since this is the default value of the log_alternate_epoch_clock_id option anyways, we treat log_alternate_epoch and log_unix_epoch as equivalent in functionality, retaining the latter to avoid breaking existing clients. Signed-off-by: Nick Neumann --- HOWTO | 13 +++++++++++++ backend.c | 2 +- cconv.c | 4 ++++ fio.1 | 11 +++++++++++ fio.h | 2 +- fio_time.h | 2 +- libfio.c | 2 +- options.c | 18 ++++++++++++++++++ os/windows/posix.c | 11 ++++++++--- rate-submit.c | 2 +- stat.c | 2 +- thread_options.h | 4 ++++ time.c | 12 ++++++------ 13 files changed, 70 insertions(+), 15 deletions(-) diff --git a/HOWTO b/HOWTO index 8c9e4135..99fb5751 100644 --- a/HOWTO +++ b/HOWTO @@ -3624,6 +3624,19 @@ Measurements and reporting write_type_log for each log type, instead of the default zero-based timestamps. +.. option:: log_alternate_epoch=bool + + If set, fio will log timestamps based on the epoch used by the clock specified + in the log_alternate_epoch_clock_id option, to the log files produced by + enabling write_type_log for each log type, instead of the default zero-based + timestamps. + +.. option:: log_alternate_epoch_clock_id=int + + Specifies the clock_id to be used by clock_gettime to obtain the alternate epoch + if either log_unix_epoch or log_alternate_epoch are true. Otherwise has no + effect. Default value is 0, or CLOCK_REALTIME. + .. option:: block_error_percentiles=bool If set, record errors in trim block-sized units from writes and trims and diff --git a/backend.c b/backend.c index c167f908..151a5615 100644 --- a/backend.c +++ b/backend.c @@ -1828,7 +1828,7 @@ static void *thread_main(void *data) if (rate_submit_init(td, sk_out)) goto err; - set_epoch_time(td, o->log_unix_epoch); + set_epoch_time(td, o->log_unix_epoch | o->log_alternate_epoch, o->log_alternate_epoch_clock_id); 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 4f8d27eb..62d02e36 100644 --- a/cconv.c +++ b/cconv.c @@ -197,6 +197,8 @@ void convert_thread_options_to_cpu(struct thread_options *o, 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->log_alternate_epoch = le32_to_cpu(top->log_alternate_epoch); + o->log_alternate_epoch_clock_id = le32_to_cpu(top->log_alternate_epoch_clock_id); o->norandommap = le32_to_cpu(top->norandommap); o->softrandommap = le32_to_cpu(top->softrandommap); o->bs_unaligned = le32_to_cpu(top->bs_unaligned); @@ -425,6 +427,8 @@ void convert_thread_options_to_net(struct thread_options_pack *top, 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->log_alternate_epoch = cpu_to_le32(o->log_alternate_epoch); + top->log_alternate_epoch_clock_id = cpu_to_le32(o->log_alternate_epoch_clock_id); 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 a3ebb67d..74f1a6ea 100644 --- a/fio.1 +++ b/fio.1 @@ -3323,6 +3323,17 @@ 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. .TP +.BI log_alternate_epoch \fR=\fPbool +If set, fio will log timestamps based on the epoch used by the clock specified +in the \fBlog_alternate_epoch_clock_id\fR option, to the log files produced by +enabling write_type_log for each log type, instead of the default zero-based +timestamps. +.TP +.BI log_alternate_epoch_clock_id \fR=\fPint +Specifies the clock_id to be used by clock_gettime to obtain the alternate epoch +if either \fBBlog_unix_epoch\fR or \fBlog_alternate_epoch\fR are true. Otherwise has no +effect. Default value is 0, or CLOCK_REALTIME. +.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 diff --git a/fio.h b/fio.h index 6bb21ebb..e9cdba94 100644 --- a/fio.h +++ b/fio.h @@ -380,7 +380,7 @@ struct thread_data { struct timespec start; /* start of this loop */ struct timespec epoch; /* time job was started */ - unsigned long long unix_epoch; /* Time job was started, unix epoch based. */ + unsigned long long alternate_epoch; /* Time job was started, clock_gettime's clock_id epoch based. */ struct timespec last_issue; long time_offset; struct timespec ts_cache; diff --git a/fio_time.h b/fio_time.h index b3bbd4c0..59f25d82 100644 --- a/fio_time.h +++ b/fio_time.h @@ -30,6 +30,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 timespec_add_msec(struct timespec *, unsigned int); -extern void set_epoch_time(struct thread_data *, int); +extern void set_epoch_time(struct thread_data *, int, int); #endif diff --git a/libfio.c b/libfio.c index 198eaf2e..01fa7452 100644 --- a/libfio.c +++ b/libfio.c @@ -142,7 +142,7 @@ void reset_all_stats(struct thread_data *td) td->ts.runtime[i] = 0; } - set_epoch_time(td, td->o.log_unix_epoch); + set_epoch_time(td, td->o.log_unix_epoch | td->o.log_alternate_epoch, td->o.log_alternate_epoch_clock_id); memcpy(&td->start, &td->epoch, sizeof(td->epoch)); memcpy(&td->iops_sample_time, &td->epoch, sizeof(td->epoch)); memcpy(&td->bw_sample_time, &td->epoch, sizeof(td->epoch)); diff --git a/options.c b/options.c index 102bcf56..0d7dc079 100644 --- a/options.c +++ b/options.c @@ -4392,6 +4392,24 @@ struct fio_option fio_options[FIO_MAX_OPTS] = { .category = FIO_OPT_C_LOG, .group = FIO_OPT_G_INVALID, }, + { + .name = "log_alternate_epoch", + .lname = "Log epoch alternate", + .type = FIO_OPT_BOOL, + .off1 = offsetof(struct thread_options, log_alternate_epoch), + .help = "Use alternate epoch time in log files. Uses the same epoch as that is used by clock_gettime with specified log_alternate_epoch_clock_id.", + .category = FIO_OPT_C_LOG, + .group = FIO_OPT_G_INVALID, + }, + { + .name = "log_alternate_epoch_clock_id", + .lname = "Log alternate epoch clock_id", + .type = FIO_OPT_INT, + .off1 = offsetof(struct thread_options, log_alternate_epoch_clock_id), + .help = "If log_alternate_epoch or log_unix_epoch is true, this option specifies the clock_id from clock_gettime whose epoch should be used. If neither of those is true, this option has no effect. Default value is 0, or CLOCK_REALTIME", + .category = FIO_OPT_C_LOG, + .group = FIO_OPT_G_INVALID, + }, { .name = "block_error_percentiles", .lname = "Block error percentiles", diff --git a/os/windows/posix.c b/os/windows/posix.c index 09c2e4a7..f1df2d76 100644 --- a/os/windows/posix.c +++ b/os/windows/posix.c @@ -537,16 +537,21 @@ int fcntl(int fildes, int cmd, ...) return 0; } +#ifndef CLOCK_MONOTONIC_RAW +#define CLOCK_MONOTONIC_RAW 4 +#endif + /* * Get the value of a local clock source. - * This implementation supports 2 clocks: CLOCK_MONOTONIC provides high-accuracy - * relative time, while CLOCK_REALTIME provides a low-accuracy wall time. + * This implementation supports 3 clocks: CLOCK_MONOTONIC/CLOCK_MONOTONIC_RAW + * provide high-accuracy relative time, while CLOCK_REALTIME provides a + * low-accuracy wall time. */ int clock_gettime(clockid_t clock_id, struct timespec *tp) { int rc = 0; - if (clock_id == CLOCK_MONOTONIC) { + if (clock_id == CLOCK_MONOTONIC || clock_id == CLOCK_MONOTONIC_RAW) { static LARGE_INTEGER freq = {{0,0}}; LARGE_INTEGER counts; uint64_t t; diff --git a/rate-submit.c b/rate-submit.c index 13dbe7a2..13a0d706 100644 --- a/rate-submit.c +++ b/rate-submit.c @@ -173,7 +173,7 @@ static int io_workqueue_init_worker_fn(struct submit_worker *sw) if (td->io_ops->post_init && td->io_ops->post_init(td)) goto err_io_init; - set_epoch_time(td, td->o.log_unix_epoch); + set_epoch_time(td, td->o.log_unix_epoch | td->o.log_alternate_epoch, td->o.log_alternate_epoch_clock_id); fio_getrusage(&td->ru_start); clear_io_state(td, 1); diff --git a/stat.c b/stat.c index 7e84058d..98f30107 100644 --- a/stat.c +++ b/stat.c @@ -2854,7 +2854,7 @@ static void __add_log_sample(struct io_log *iolog, union io_sample_data data, s = get_sample(iolog, cur_log, cur_log->nr_samples); s->data = data; - s->time = t + (iolog->td ? iolog->td->unix_epoch : 0); + s->time = t + (iolog->td ? iolog->td->alternate_epoch : 0); io_sample_set_ddir(iolog, s, ddir); s->bs = bs; s->priority = priority; diff --git a/thread_options.h b/thread_options.h index 8f4c8a59..450e7dde 100644 --- a/thread_options.h +++ b/thread_options.h @@ -166,6 +166,8 @@ struct thread_options { unsigned int log_gz; unsigned int log_gz_store; unsigned int log_unix_epoch; + unsigned int log_alternate_epoch; + unsigned int log_alternate_epoch_clock_id; unsigned int norandommap; unsigned int softrandommap; unsigned int bs_unaligned; @@ -482,6 +484,8 @@ struct thread_options_pack { uint32_t log_gz; uint32_t log_gz_store; uint32_t log_unix_epoch; + uint32_t log_alternate_epoch; + uint32_t log_alternate_epoch_clock_id; uint32_t norandommap; uint32_t softrandommap; uint32_t bs_unaligned; diff --git a/time.c b/time.c index cd0e2a89..5c4d6de0 100644 --- a/time.c +++ b/time.c @@ -172,14 +172,14 @@ void set_genesis_time(void) fio_gettime(&genesis, NULL); } -void set_epoch_time(struct thread_data *td, int log_unix_epoch) +void set_epoch_time(struct thread_data *td, int log_alternate_epoch, clockid_t clock_id) { 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; + if (log_alternate_epoch) { + struct timespec ts; + clock_gettime(clock_id, &ts); + td->alternate_epoch = (unsigned long long)(ts.tv_sec) * 1000 + + (unsigned long long)(ts.tv_nsec) / 1000000; } } -- 2.25.1