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 <nick@pcpartpicker.com>

diff --git a/HOWTO b/HOWTO
index 8c9e41356b9586b33fa17e4068d50620eb6be551..99fb575126483aa050c1d86abbc4f41c56ede13e 100644 (file)
--- 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 c167f908625f39fd8e344c9f75c705f7fd71adf4..151a561555fc45895cf29fa780d0b8b5cf399b44 100644 (file)
--- 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 4f8d27eb2dcec47244dfab3b902205b32a21da5e..62d02e366e06473da2b74b55a090d0e46499af16 100644 (file)
--- 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 a3ebb67d36df6884ea1ce95ca5cfb48946bec0a6..74f1a6ea07e9039f76503fc2b88d4c383c3825b6 100644 (file)
--- 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 6bb21ebb2ace311c3b4643bb6adbfbbcf045b444..e9cdba94a6091f0fb7e9f72a34e2dd6b317da64b 100644 (file)
--- 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 b3bbd4c011c2518aea5cbf5523f514136f8601b3..59f25d82a54d0917472da4a6f900d825ce6daa12 100644 (file)
--- 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 198eaf2eb723f744cbc279cd3dff51a1be64bd00..01fa74529fa9fedd1833e33082b73b1198bf19e1 100644 (file)
--- 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 102bcf5661a0c0fbffd54a61ad85281809250d3a..0d7dc0797312aef62f5f79f4f227bfed5dfe6b3c 100644 (file)
--- 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 09c2e4a7857bd4121441b866c70657a935fde730..f1df2d76e0abe4ec0891be04fb2632366832512d 100644 (file)
--- 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 13dbe7a2e9ff8f3face1619e750b83018ba222df..13a0d706e078be41a53a31efc8d0a70f511d648f 100644 (file)
--- 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 7e84058d9b911294956d0970e218cf97ea0a3344..98f30107d1ada1a3f49ebcb580089a87a884ffeb 100644 (file)
--- 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 8f4c8a5996aefa912d13f6ec263d82d9d05db033..450e7ddeee25d2ac471e79da637bbf8e168d4502 100644 (file)
--- 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 cd0e2a89144b59a565d88fab6192dda951a8ff2b..5c4d6de0399c5cc681e9ca362c019870baf9db98 100644 (file)
--- 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;
        }
 }