diff mbox series

[v1,02/26] qemu-io-cmds: use clock_gettime for benchmarking

Message ID 20190530101603.22254-3-alex.bennee@linaro.org
State New
Headers show
Series testing/next queue (iotests, docker, tests/vm) | expand

Commit Message

Alex Bennée May 30, 2019, 10:15 a.m. UTC 
The previous use of gettimeofday() ran into undefined behaviour when
we ended up doing a div 0 for a very short operation. This is because
gettimeofday only works at the microsecond level as well as being
prone to discontinuous jumps in system time. Using clock_gettime with
CLOCK_MONOTONIC gives greater precision and alleviates some of the
potential problems with time jumping around.

We could use CLOCK_MONOTONIC_RAW to avoid being tripped up by NTP and
adjtime but that is Linux specific so I decided it would do for now.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

---
 qemu-io-cmds.c | 69 +++++++++++++++++++++++++-------------------------
 1 file changed, 35 insertions(+), 34 deletions(-)

-- 
2.20.1

Comments

Richard Henderson May 30, 2019, 6:41 p.m. UTC | #1 
On 5/30/19 5:15 AM, Alex Bennée wrote:
> -static struct timeval tsub(struct timeval t1, struct timeval t2)

> +static struct timespec tsub(struct timespec t1, struct timespec t2)

>  {

> -    t1.tv_usec -= t2.tv_usec;

> -    if (t1.tv_usec < 0) {

> -        t1.tv_usec += 1000000;

> +    t1.tv_nsec -= t2.tv_nsec;

> +    if (t1.tv_nsec < 0) {

> +        t1.tv_nsec += 1000000000;


Rather than counting zeros, should we move or copy NANOSECONDS_PER_SECOND?

> +    double time = (double)tv.tv_sec + ((double)tv.tv_nsec / 1000000000.0);


On that same vein, I'll note this can also be spelled "1e9".
Also, the casts to double are superfluous, once we have one FP constant.

> +static void timestr(struct timespec *tv, char *ts, size_t size, int format)

>  {

> -    double usec = (double)tv->tv_usec / 1000000.0;

> +    double nsec = (double)tv->tv_nsec / 1000000000.0;


Similarly.

>  

>      if (format & TERSE_FIXED_TIME) {

>          if (!HOURS(tv->tv_sec)) {

>              snprintf(ts, size, "%u:%02u.%02u",

>                      (unsigned int) MINUTES(tv->tv_sec),

>                      (unsigned int) SECONDS(tv->tv_sec),

> -                    (unsigned int) (usec * 100));

> +                    (unsigned int) (nsec * 100000));


The multiplier here is wrong.

The existing formatting here is bonkers, which doesn't help.  Why should we
convert to double, divide into a fraction of a second, shift the decimal place,
and truncate conversion to integer?

The formatting should clearly be

  snprintf(ts, size, "%u:%05.2f",
           (unsigned int) MINUTES(tv->tv_sec),
           SECONDS(tv->tv_sec) + nsec);

so that the complete seconds plus fraction of a second is rounded to two digits
after the decimal point, and is left-padded with 0's so that the entire number
fits in 5 characters, not forgetting the decimal point itself (i.e. 00.00).

Likewise to the other two occurrences in this function.


r~
diff mbox series

Patch

diff --git a/qemu-io-cmds.c b/qemu-io-cmds.c
index 30a7d9a13bf..f6701e3b8a8 100644
--- a/qemu-io-cmds.c
+++ b/qemu-io-cmds.c
@@ -248,20 +248,21 @@  static void cvtstr(double value, char *str, size_t size)
 
 
 
-static struct timeval tsub(struct timeval t1, struct timeval t2)
+static struct timespec tsub(struct timespec t1, struct timespec t2)
 {
-    t1.tv_usec -= t2.tv_usec;
-    if (t1.tv_usec < 0) {
-        t1.tv_usec += 1000000;
+    t1.tv_nsec -= t2.tv_nsec;
+    if (t1.tv_nsec < 0) {
+        t1.tv_nsec += 1000000000;
         t1.tv_sec--;
     }
     t1.tv_sec -= t2.tv_sec;
     return t1;
 }
 
-static double tdiv(double value, struct timeval tv)
+static double tdiv(double value, struct timespec tv)
 {
-    return value / ((double)tv.tv_sec + ((double)tv.tv_usec / 1000000.0));
+    double time = (double)tv.tv_sec + ((double)tv.tv_nsec / 1000000000.0);
+    return value / time;
 }
 
 #define HOURS(sec)      ((sec) / (60 * 60))
@@ -274,16 +275,16 @@  enum {
     VERBOSE_FIXED_TIME  = 0x2,
 };
 
-static void timestr(struct timeval *tv, char *ts, size_t size, int format)
+static void timestr(struct timespec *tv, char *ts, size_t size, int format)
 {
-    double usec = (double)tv->tv_usec / 1000000.0;
+    double nsec = (double)tv->tv_nsec / 1000000000.0;
 
     if (format & TERSE_FIXED_TIME) {
         if (!HOURS(tv->tv_sec)) {
             snprintf(ts, size, "%u:%02u.%02u",
                     (unsigned int) MINUTES(tv->tv_sec),
                     (unsigned int) SECONDS(tv->tv_sec),
-                    (unsigned int) (usec * 100));
+                    (unsigned int) (nsec * 100000));
             return;
         }
         format |= VERBOSE_FIXED_TIME; /* fallback if hours needed */
@@ -294,9 +295,9 @@  static void timestr(struct timeval *tv, char *ts, size_t size, int format)
                 (unsigned int) HOURS(tv->tv_sec),
                 (unsigned int) MINUTES(tv->tv_sec),
                 (unsigned int) SECONDS(tv->tv_sec),
-                (unsigned int) (usec * 100));
+                (unsigned int) (nsec * 100000));
     } else {
-        snprintf(ts, size, "0.%04u sec", (unsigned int) (usec * 10000));
+        snprintf(ts, size, "0.%04u sec", (unsigned int) (nsec * 10000000));
     }
 }
 
@@ -376,7 +377,7 @@  static void dump_buffer(const void *buffer, int64_t offset, int64_t len)
     }
 }
 
-static void print_report(const char *op, struct timeval *t, int64_t offset,
+static void print_report(const char *op, struct timespec *t, int64_t offset,
                          int64_t count, int64_t total, int cnt, bool Cflag)
 {
     char s1[64], s2[64], ts[64];
@@ -649,7 +650,7 @@  static const cmdinfo_t read_cmd = {
 
 static int read_f(BlockBackend *blk, int argc, char **argv)
 {
-    struct timeval t1, t2;
+    struct timespec t1, t2;
     bool Cflag = false, qflag = false, vflag = false;
     bool Pflag = false, sflag = false, lflag = false, bflag = false;
     int c, cnt, ret;
@@ -758,13 +759,13 @@  static int read_f(BlockBackend *blk, int argc, char **argv)
 
     buf = qemu_io_alloc(blk, count, 0xab);
 
-    gettimeofday(&t1, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t1);
     if (bflag) {
         ret = do_load_vmstate(blk, buf, offset, count, &total);
     } else {
         ret = do_pread(blk, buf, offset, count, &total);
     }
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
     if (ret < 0) {
         printf("read failed: %s\n", strerror(-ret));
@@ -836,7 +837,7 @@  static const cmdinfo_t readv_cmd = {
 
 static int readv_f(BlockBackend *blk, int argc, char **argv)
 {
-    struct timeval t1, t2;
+    struct timespec t1, t2;
     bool Cflag = false, qflag = false, vflag = false;
     int c, cnt, ret;
     char *buf;
@@ -891,9 +892,9 @@  static int readv_f(BlockBackend *blk, int argc, char **argv)
         return -EINVAL;
     }
 
-    gettimeofday(&t1, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t1);
     ret = do_aio_readv(blk, &qiov, offset, &total);
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
     if (ret < 0) {
         printf("readv failed: %s\n", strerror(-ret));
@@ -972,7 +973,7 @@  static const cmdinfo_t write_cmd = {
 
 static int write_f(BlockBackend *blk, int argc, char **argv)
 {
-    struct timeval t1, t2;
+    struct timespec t1, t2;
     bool Cflag = false, qflag = false, bflag = false;
     bool Pflag = false, zflag = false, cflag = false;
     int flags = 0;
@@ -1091,7 +1092,7 @@  static int write_f(BlockBackend *blk, int argc, char **argv)
         buf = qemu_io_alloc(blk, count, pattern);
     }
 
-    gettimeofday(&t1, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t1);
     if (bflag) {
         ret = do_save_vmstate(blk, buf, offset, count, &total);
     } else if (zflag) {
@@ -1101,7 +1102,7 @@  static int write_f(BlockBackend *blk, int argc, char **argv)
     } else {
         ret = do_pwrite(blk, buf, offset, count, flags, &total);
     }
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
     if (ret < 0) {
         printf("write failed: %s\n", strerror(-ret));
@@ -1160,7 +1161,7 @@  static const cmdinfo_t writev_cmd = {
 
 static int writev_f(BlockBackend *blk, int argc, char **argv)
 {
-    struct timeval t1, t2;
+    struct timespec t1, t2;
     bool Cflag = false, qflag = false;
     int flags = 0;
     int c, cnt, ret;
@@ -1213,9 +1214,9 @@  static int writev_f(BlockBackend *blk, int argc, char **argv)
         return -EINVAL;
     }
 
-    gettimeofday(&t1, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t1);
     ret = do_aio_writev(blk, &qiov, offset, flags, &total);
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
     if (ret < 0) {
         printf("writev failed: %s\n", strerror(-ret));
@@ -1250,15 +1251,15 @@  struct aio_ctx {
     bool zflag;
     BlockAcctCookie acct;
     int pattern;
-    struct timeval t1;
+    struct timespec t1;
 };
 
 static void aio_write_done(void *opaque, int ret)
 {
     struct aio_ctx *ctx = opaque;
-    struct timeval t2;
+    struct timespec t2;
 
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
 
     if (ret < 0) {
@@ -1288,9 +1289,9 @@  out:
 static void aio_read_done(void *opaque, int ret)
 {
     struct aio_ctx *ctx = opaque;
-    struct timeval t2;
+    struct timespec t2;
 
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
     if (ret < 0) {
         printf("readv failed: %s\n", strerror(-ret));
@@ -1425,7 +1426,7 @@  static int aio_read_f(BlockBackend *blk, int argc, char **argv)
         return -EINVAL;
     }
 
-    gettimeofday(&ctx->t1, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &ctx->t1);
     block_acct_start(blk_get_stats(blk), &ctx->acct, ctx->qiov.size,
                      BLOCK_ACCT_READ);
     blk_aio_preadv(blk, ctx->offset, &ctx->qiov, 0, aio_read_done, ctx);
@@ -1570,7 +1571,7 @@  static int aio_write_f(BlockBackend *blk, int argc, char **argv)
             return -EINVAL;
         }
 
-        gettimeofday(&ctx->t1, NULL);
+        clock_gettime(CLOCK_MONOTONIC, &ctx->t1);
         block_acct_start(blk_get_stats(blk), &ctx->acct, ctx->qiov.size,
                          BLOCK_ACCT_WRITE);
 
@@ -1746,7 +1747,7 @@  static const cmdinfo_t discard_cmd = {
 
 static int discard_f(BlockBackend *blk, int argc, char **argv)
 {
-    struct timeval t1, t2;
+    struct timespec t1, t2;
     bool Cflag = false, qflag = false;
     int c, ret;
     int64_t offset, bytes;
@@ -1787,9 +1788,9 @@  static int discard_f(BlockBackend *blk, int argc, char **argv)
         return -EINVAL;
     }
 
-    gettimeofday(&t1, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t1);
     ret = blk_pdiscard(blk, offset, bytes);
-    gettimeofday(&t2, NULL);
+    clock_gettime(CLOCK_MONOTONIC, &t2);
 
     if (ret < 0) {
         printf("discard failed: %s\n", strerror(-ret));