qemu-io-cmds: use clock_gettime for benchmarking

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>
This commit is contained in:
Alex Bennée 2019-05-29 17:16:32 +01:00
parent 9b109f566a
commit 50290c002c

View File

@ -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; t1.tv_nsec -= t2.tv_nsec;
if (t1.tv_usec < 0) { if (t1.tv_nsec < 0) {
t1.tv_usec += 1000000; t1.tv_nsec += NANOSECONDS_PER_SECOND;
t1.tv_sec--; t1.tv_sec--;
} }
t1.tv_sec -= t2.tv_sec; t1.tv_sec -= t2.tv_sec;
return t1; 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 seconds = tv.tv_sec + (tv.tv_nsec / 1e9);
return value / seconds;
} }
#define HOURS(sec) ((sec) / (60 * 60)) #define HOURS(sec) ((sec) / (60 * 60))
@ -274,29 +275,27 @@ enum {
VERBOSE_FIXED_TIME = 0x2, 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 frac_sec = tv->tv_nsec / 1e9;
if (format & TERSE_FIXED_TIME) { if (format & TERSE_FIXED_TIME) {
if (!HOURS(tv->tv_sec)) { if (!HOURS(tv->tv_sec)) {
snprintf(ts, size, "%u:%02u.%02u", snprintf(ts, size, "%u:%05.2f",
(unsigned int) MINUTES(tv->tv_sec), (unsigned int) MINUTES(tv->tv_sec),
(unsigned int) SECONDS(tv->tv_sec), SECONDS(tv->tv_sec) + frac_sec);
(unsigned int) (usec * 100));
return; return;
} }
format |= VERBOSE_FIXED_TIME; /* fallback if hours needed */ format |= VERBOSE_FIXED_TIME; /* fallback if hours needed */
} }
if ((format & VERBOSE_FIXED_TIME) || tv->tv_sec) { if ((format & VERBOSE_FIXED_TIME) || tv->tv_sec) {
snprintf(ts, size, "%u:%02u:%02u.%02u", snprintf(ts, size, "%u:%02u:%05.2f",
(unsigned int) HOURS(tv->tv_sec), (unsigned int) HOURS(tv->tv_sec),
(unsigned int) MINUTES(tv->tv_sec), (unsigned int) MINUTES(tv->tv_sec),
(unsigned int) SECONDS(tv->tv_sec), SECONDS(tv->tv_sec) + frac_sec);
(unsigned int) (usec * 100));
} else { } else {
snprintf(ts, size, "0.%04u sec", (unsigned int) (usec * 10000)); snprintf(ts, size, "%05.2f sec", frac_sec);
} }
} }
@ -376,7 +375,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) int64_t count, int64_t total, int cnt, bool Cflag)
{ {
char s1[64], s2[64], ts[64]; char s1[64], s2[64], ts[64];
@ -649,7 +648,7 @@ static const cmdinfo_t read_cmd = {
static int read_f(BlockBackend *blk, int argc, char **argv) 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 Cflag = false, qflag = false, vflag = false;
bool Pflag = false, sflag = false, lflag = false, bflag = false; bool Pflag = false, sflag = false, lflag = false, bflag = false;
int c, cnt, ret; int c, cnt, ret;
@ -758,13 +757,13 @@ static int read_f(BlockBackend *blk, int argc, char **argv)
buf = qemu_io_alloc(blk, count, 0xab); buf = qemu_io_alloc(blk, count, 0xab);
gettimeofday(&t1, NULL); clock_gettime(CLOCK_MONOTONIC, &t1);
if (bflag) { if (bflag) {
ret = do_load_vmstate(blk, buf, offset, count, &total); ret = do_load_vmstate(blk, buf, offset, count, &total);
} else { } else {
ret = do_pread(blk, buf, offset, count, &total); ret = do_pread(blk, buf, offset, count, &total);
} }
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
printf("read failed: %s\n", strerror(-ret)); printf("read failed: %s\n", strerror(-ret));
@ -836,7 +835,7 @@ static const cmdinfo_t readv_cmd = {
static int readv_f(BlockBackend *blk, int argc, char **argv) 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; bool Cflag = false, qflag = false, vflag = false;
int c, cnt, ret; int c, cnt, ret;
char *buf; char *buf;
@ -891,9 +890,9 @@ static int readv_f(BlockBackend *blk, int argc, char **argv)
return -EINVAL; return -EINVAL;
} }
gettimeofday(&t1, NULL); clock_gettime(CLOCK_MONOTONIC, &t1);
ret = do_aio_readv(blk, &qiov, offset, &total); ret = do_aio_readv(blk, &qiov, offset, &total);
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
printf("readv failed: %s\n", strerror(-ret)); printf("readv failed: %s\n", strerror(-ret));
@ -972,7 +971,7 @@ static const cmdinfo_t write_cmd = {
static int write_f(BlockBackend *blk, int argc, char **argv) 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 Cflag = false, qflag = false, bflag = false;
bool Pflag = false, zflag = false, cflag = false; bool Pflag = false, zflag = false, cflag = false;
int flags = 0; int flags = 0;
@ -1091,7 +1090,7 @@ static int write_f(BlockBackend *blk, int argc, char **argv)
buf = qemu_io_alloc(blk, count, pattern); buf = qemu_io_alloc(blk, count, pattern);
} }
gettimeofday(&t1, NULL); clock_gettime(CLOCK_MONOTONIC, &t1);
if (bflag) { if (bflag) {
ret = do_save_vmstate(blk, buf, offset, count, &total); ret = do_save_vmstate(blk, buf, offset, count, &total);
} else if (zflag) { } else if (zflag) {
@ -1101,7 +1100,7 @@ static int write_f(BlockBackend *blk, int argc, char **argv)
} else { } else {
ret = do_pwrite(blk, buf, offset, count, flags, &total); ret = do_pwrite(blk, buf, offset, count, flags, &total);
} }
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
printf("write failed: %s\n", strerror(-ret)); printf("write failed: %s\n", strerror(-ret));
@ -1160,7 +1159,7 @@ static const cmdinfo_t writev_cmd = {
static int writev_f(BlockBackend *blk, int argc, char **argv) static int writev_f(BlockBackend *blk, int argc, char **argv)
{ {
struct timeval t1, t2; struct timespec t1, t2;
bool Cflag = false, qflag = false; bool Cflag = false, qflag = false;
int flags = 0; int flags = 0;
int c, cnt, ret; int c, cnt, ret;
@ -1213,9 +1212,9 @@ static int writev_f(BlockBackend *blk, int argc, char **argv)
return -EINVAL; return -EINVAL;
} }
gettimeofday(&t1, NULL); clock_gettime(CLOCK_MONOTONIC, &t1);
ret = do_aio_writev(blk, &qiov, offset, flags, &total); ret = do_aio_writev(blk, &qiov, offset, flags, &total);
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
printf("writev failed: %s\n", strerror(-ret)); printf("writev failed: %s\n", strerror(-ret));
@ -1250,15 +1249,15 @@ struct aio_ctx {
bool zflag; bool zflag;
BlockAcctCookie acct; BlockAcctCookie acct;
int pattern; int pattern;
struct timeval t1; struct timespec t1;
}; };
static void aio_write_done(void *opaque, int ret) static void aio_write_done(void *opaque, int ret)
{ {
struct aio_ctx *ctx = opaque; struct aio_ctx *ctx = opaque;
struct timeval t2; struct timespec t2;
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
@ -1288,9 +1287,9 @@ out:
static void aio_read_done(void *opaque, int ret) static void aio_read_done(void *opaque, int ret)
{ {
struct aio_ctx *ctx = opaque; struct aio_ctx *ctx = opaque;
struct timeval t2; struct timespec t2;
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
printf("readv failed: %s\n", strerror(-ret)); printf("readv failed: %s\n", strerror(-ret));
@ -1425,7 +1424,7 @@ static int aio_read_f(BlockBackend *blk, int argc, char **argv)
return -EINVAL; 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_start(blk_get_stats(blk), &ctx->acct, ctx->qiov.size,
BLOCK_ACCT_READ); BLOCK_ACCT_READ);
blk_aio_preadv(blk, ctx->offset, &ctx->qiov, 0, aio_read_done, ctx); blk_aio_preadv(blk, ctx->offset, &ctx->qiov, 0, aio_read_done, ctx);
@ -1570,7 +1569,7 @@ static int aio_write_f(BlockBackend *blk, int argc, char **argv)
return -EINVAL; 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_start(blk_get_stats(blk), &ctx->acct, ctx->qiov.size,
BLOCK_ACCT_WRITE); BLOCK_ACCT_WRITE);
@ -1746,7 +1745,7 @@ static const cmdinfo_t discard_cmd = {
static int discard_f(BlockBackend *blk, int argc, char **argv) static int discard_f(BlockBackend *blk, int argc, char **argv)
{ {
struct timeval t1, t2; struct timespec t1, t2;
bool Cflag = false, qflag = false; bool Cflag = false, qflag = false;
int c, ret; int c, ret;
int64_t offset, bytes; int64_t offset, bytes;
@ -1787,9 +1786,9 @@ static int discard_f(BlockBackend *blk, int argc, char **argv)
return -EINVAL; return -EINVAL;
} }
gettimeofday(&t1, NULL); clock_gettime(CLOCK_MONOTONIC, &t1);
ret = blk_pdiscard(blk, offset, bytes); ret = blk_pdiscard(blk, offset, bytes);
gettimeofday(&t2, NULL); clock_gettime(CLOCK_MONOTONIC, &t2);
if (ret < 0) { if (ret < 0) {
printf("discard failed: %s\n", strerror(-ret)); printf("discard failed: %s\n", strerror(-ret));