From 504bc961f25d09ef304412cd365101912bb3fd6d Mon Sep 17 00:00:00 2001 From: Jens Axboe Date: Mon, 1 Dec 2014 09:42:48 -0700 Subject: [PATCH] Bump disk util stats from 32 to 64-bit values Robert reports: A long run can result in wrapping in the disk stats (ios, merge, ticks, in_queue). In this example, there were 212,245,615,134 read IOs (that is from uint64_t total_io_u[3]): read : io=101207GB, bw=491309KB/s, iops=982618, runt=216000016msec cpu : usr=0.09%, sys=4.33%, ctx=152784302066, majf=0, minf=2928 IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.5%, 16=0.5%, 32=1.0%, >=64=1.0% submit : 0=0.0%, 4=18.0%, 8=6.6%, 16=8.5%, 32=0.0%, 64=0.0%, >=64=0.0% complete : 0=0.0%, 4=0.0%, 8=0.0%, 16=15.0%, 32=0.1%, 64=0.1%, >=64=0.1% issued : total=r=212245615134/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0 latency : target=0, window=0, percentile=100.00%, depth=96 Run status group 0 (all jobs): READ: io=101207GB, aggrb=491309KB/s, minb=491309KB/s, maxb=491309KB/s, mint=216000016msec, maxt=216000016msec All the disk stats, however, wrap at ios=4,294,967,295 (32 bit). In this case it caught sdi falling a bit behind the others, but all of them have wrapped multiple times. Disk stats (read/write): sdb: ios=796157304/0, merge=0/0, ticks=722039638/0, in_queue=735284999, util=100.00% sdc: ios=725235994/0, merge=0/0, ticks=725893305/0, in_queue=738790349, util=100.00% sdd: ios=722370867/0, merge=0/0, ticks=724540972/0, in_queue=738926102, util=100.00% sde: ios=722490025/0, merge=0/0, ticks=724775894/0, in_queue=745581851, util=100.00% sdf: ios=719665329/0, merge=0/0, ticks=724281840/0, in_queue=740201203, util=100.00% sdg: ios=721386377/0, merge=0/0, ticks=725529483/0, in_queue=740729310, util=100.00% sdh: ios=720461888/0, merge=0/0, ticks=724759222/0, in_queue=741212131, util=100.00% sdi: ios=3280272329/0, merge=0/0, ticks=3337080572/0, in_queue=3340290775, util=81.57% sdj: ios=717395167/0, merge=0/0, ticks=723762993/0, in_queue=739136654, util=100.00% sdk: ios=824804416/0, merge=0/0, ticks=722973383/0, in_queue=734915061, util=100.00% sdl: ios=787317365/0, merge=0/0, ticks=720963594/0, in_queue=736506238, util=100.00% sdm: ios=791112845/0, merge=0/0, ticks=723371287/0, in_queue=745590636, util=100.00% sdn: ios=786009870/0, merge=0/0, ticks=721111447/0, in_queue=733786474, util=100.00% sdo: ios=787226466/0, merge=0/0, ticks=722200707/0, in_queue=737673635, util=100.00% sdp: ios=789062478/0, merge=0/0, ticks=723648481/0, in_queue=737820918, util=100.00% sdq: ios=786121713/0, merge=0/0, ticks=722203635/0, in_queue=752578258, util=100.00% These structures are the reason: struct disk_util_stats { uint32_t ios[2]; uint32_t merges[2]; uint64_t sectors[2]; uint32_t ticks[2]; uint32_t io_ticks; uint32_t time_in_queue; uint64_t msec; }; struct disk_util_agg { uint32_t ios[2]; uint32_t merges[2]; uint64_t sectors[2]; uint32_t ticks[2]; uint32_t io_ticks; uint32_t time_in_queue; uint32_t slavecount; fio_fp64_t max_util; }; Signed-off-by: Jens Axboe --- client.c | 20 ++++++------ diskutil.c | 92 +++++++++++++++++++++++++++++++----------------------- diskutil.h | 21 +++++++------ server.c | 20 ++++++------ server.h | 2 +- 5 files changed, 85 insertions(+), 70 deletions(-) diff --git a/client.c b/client.c index 2c10c037..3cb7c1c5 100644 --- a/client.c +++ b/client.c @@ -974,14 +974,14 @@ static void convert_agg(struct disk_util_agg *agg) int i; for (i = 0; i < 2; i++) { - agg->ios[i] = le32_to_cpu(agg->ios[i]); - agg->merges[i] = le32_to_cpu(agg->merges[i]); + agg->ios[i] = le64_to_cpu(agg->ios[i]); + agg->merges[i] = le64_to_cpu(agg->merges[i]); agg->sectors[i] = le64_to_cpu(agg->sectors[i]); - agg->ticks[i] = le32_to_cpu(agg->ticks[i]); + agg->ticks[i] = le64_to_cpu(agg->ticks[i]); } - agg->io_ticks = le32_to_cpu(agg->io_ticks); - agg->time_in_queue = le32_to_cpu(agg->time_in_queue); + agg->io_ticks = le64_to_cpu(agg->io_ticks); + agg->time_in_queue = le64_to_cpu(agg->time_in_queue); agg->slavecount = le32_to_cpu(agg->slavecount); agg->max_util.u.f = fio_uint64_to_double(le64_to_cpu(agg->max_util.u.i)); } @@ -991,14 +991,14 @@ static void convert_dus(struct disk_util_stat *dus) int i; for (i = 0; i < 2; i++) { - dus->s.ios[i] = le32_to_cpu(dus->s.ios[i]); - dus->s.merges[i] = le32_to_cpu(dus->s.merges[i]); + dus->s.ios[i] = le64_to_cpu(dus->s.ios[i]); + dus->s.merges[i] = le64_to_cpu(dus->s.merges[i]); dus->s.sectors[i] = le64_to_cpu(dus->s.sectors[i]); - dus->s.ticks[i] = le32_to_cpu(dus->s.ticks[i]); + dus->s.ticks[i] = le64_to_cpu(dus->s.ticks[i]); } - dus->s.io_ticks = le32_to_cpu(dus->s.io_ticks); - dus->s.time_in_queue = le32_to_cpu(dus->s.time_in_queue); + dus->s.io_ticks = le64_to_cpu(dus->s.io_ticks); + dus->s.time_in_queue = le64_to_cpu(dus->s.time_in_queue); dus->s.msec = le64_to_cpu(dus->s.msec); } diff --git a/diskutil.c b/diskutil.c index 51da8a08..98ae2fe3 100644 --- a/diskutil.c +++ b/diskutil.c @@ -62,14 +62,18 @@ static int get_io_ticks(struct disk_util *du, struct disk_util_stat *dus) dprint(FD_DISKUTIL, "%s: %s", du->path, p); - ret = sscanf(p, "%u %u %llu %u %u %u %llu %u %u %u %u\n", - &dus->s.ios[0], - &dus->s.merges[0], §ors[0], - &dus->s.ticks[0], &dus->s.ios[1], - &dus->s.merges[1], §ors[1], - &dus->s.ticks[1], &in_flight, - &dus->s.io_ticks, - &dus->s.time_in_queue); + ret = sscanf(p, "%llu %llu %llu %llu %llu %llu %llu %llu %u %llu %llu\n", + (unsigned long long *) &dus->s.ios[0], + (unsigned long long *) &dus->s.merges[0], + §ors[0], + (unsigned long long *) &dus->s.ticks[0], + (unsigned long long *) &dus->s.ios[1], + (unsigned long long *) &dus->s.merges[1], + §ors[1], + (unsigned long long *) &dus->s.ticks[1], + &in_flight, + (unsigned long long *) &dus->s.io_ticks, + (unsigned long long *) &dus->s.time_in_queue); fclose(f); dprint(FD_DISKUTIL, "%s: stat read ok? %d\n", du->path, ret == 1); dus->s.sectors[0] = sectors[0]; @@ -497,26 +501,27 @@ static void show_agg_stats(struct disk_util_agg *agg, int terse) return; if (!terse) { - log_info(", aggrios=%u/%u, aggrmerge=%u/%u, aggrticks=%u/%u," - " aggrin_queue=%u, aggrutil=%3.2f%%", - agg->ios[0] / agg->slavecount, - agg->ios[1] / agg->slavecount, - agg->merges[0] / agg->slavecount, - agg->merges[1] / agg->slavecount, - agg->ticks[0] / agg->slavecount, - agg->ticks[1] / agg->slavecount, - agg->time_in_queue / agg->slavecount, - agg->max_util.u.f); + log_info(", aggrios=%llu/%llu, aggrmerge=%llu/%llu, " + "aggrticks=%llu/%llu, aggrin_queue=%llu, " + "aggrutil=%3.2f%%", + (unsigned long long) agg->ios[0] / agg->slavecount, + (unsigned long long) agg->ios[1] / agg->slavecount, + (unsigned long long) agg->merges[0] / agg->slavecount, + (unsigned long long) agg->merges[1] / agg->slavecount, + (unsigned long long) agg->ticks[0] / agg->slavecount, + (unsigned long long) agg->ticks[1] / agg->slavecount, + (unsigned long long) agg->time_in_queue / agg->slavecount, + agg->max_util.u.f); } else { - log_info(";slaves;%u;%u;%u;%u;%u;%u;%u;%3.2f%%", - agg->ios[0] / agg->slavecount, - agg->ios[1] / agg->slavecount, - agg->merges[0] / agg->slavecount, - agg->merges[1] / agg->slavecount, - agg->ticks[0] / agg->slavecount, - agg->ticks[1] / agg->slavecount, - agg->time_in_queue / agg->slavecount, - agg->max_util.u.f); + log_info(";slaves;%llu;%llu;%llu;%llu;%llu;%llu;%llu;%3.2f%%", + (unsigned long long) agg->ios[0] / agg->slavecount, + (unsigned long long) agg->ios[1] / agg->slavecount, + (unsigned long long) agg->merges[0] / agg->slavecount, + (unsigned long long) agg->merges[1] / agg->slavecount, + (unsigned long long) agg->ticks[0] / agg->slavecount, + (unsigned long long) agg->ticks[1] / agg->slavecount, + (unsigned long long) agg->time_in_queue / agg->slavecount, + agg->max_util.u.f); } } @@ -586,19 +591,28 @@ void print_disk_util(struct disk_util_stat *dus, struct disk_util_agg *agg, if (agg->slavecount) log_info(" "); - log_info(" %s: ios=%u/%u, merge=%u/%u, ticks=%u/%u, " - "in_queue=%u, util=%3.2f%%", dus->name, - dus->s.ios[0], dus->s.ios[1], - dus->s.merges[0], dus->s.merges[1], - dus->s.ticks[0], dus->s.ticks[1], - dus->s.time_in_queue, util); + log_info(" %s: ios=%llu/%llu, merge=%llu/%llu, " + "ticks=%llu/%llu, in_queue=%llu, util=%3.2f%%", + dus->name, + (unsigned long long) dus->s.ios[0], + (unsigned long long) dus->s.ios[1], + (unsigned long long) dus->s.merges[0], + (unsigned long long) dus->s.merges[1], + (unsigned long long) dus->s.ticks[0], + (unsigned long long) dus->s.ticks[1], + (unsigned long long) dus->s.time_in_queue, + util); } else { - log_info(";%s;%u;%u;%u;%u;%u;%u;%u;%3.2f%%", - dus->name, dus->s.ios[0], - dus->s.ios[1], dus->s.merges[0], - dus->s.merges[1], dus->s.ticks[0], - dus->s.ticks[1], - dus->s.time_in_queue, util); + log_info(";%s;%llu;%llu;%llu;%llu;%llu;%llu;%llu;%3.2f%%", + dus->name, + (unsigned long long) dus->s.ios[0], + (unsigned long long) dus->s.ios[1], + (unsigned long long) dus->s.merges[0], + (unsigned long long) dus->s.merges[1], + (unsigned long long) dus->s.ticks[0], + (unsigned long long) dus->s.ticks[1], + (unsigned long long) dus->s.time_in_queue, + util); } /* diff --git a/diskutil.h b/diskutil.h index 8623fd72..c0ae0ed0 100644 --- a/diskutil.h +++ b/diskutil.h @@ -6,12 +6,12 @@ extern volatile int helper_exit; struct disk_util_stats { - uint32_t ios[2]; - uint32_t merges[2]; + uint64_t ios[2]; + uint64_t merges[2]; uint64_t sectors[2]; - uint32_t ticks[2]; - uint32_t io_ticks; - uint32_t time_in_queue; + uint64_t ticks[2]; + uint64_t io_ticks; + uint64_t time_in_queue; uint64_t msec; }; @@ -24,13 +24,14 @@ struct disk_util_stat { }; struct disk_util_agg { - uint32_t ios[2]; - uint32_t merges[2]; + uint64_t ios[2]; + uint64_t merges[2]; uint64_t sectors[2]; - uint32_t ticks[2]; - uint32_t io_ticks; - uint32_t time_in_queue; + uint64_t ticks[2]; + uint64_t io_ticks; + uint64_t time_in_queue; uint32_t slavecount; + uint32_t pad; fio_fp64_t max_util; }; diff --git a/server.c b/server.c index c4ab906f..ede291fa 100644 --- a/server.c +++ b/server.c @@ -1178,14 +1178,14 @@ static void convert_agg(struct disk_util_agg *dst, struct disk_util_agg *src) int i; for (i = 0; i < 2; i++) { - dst->ios[i] = cpu_to_le32(src->ios[i]); - dst->merges[i] = cpu_to_le32(src->merges[i]); + dst->ios[i] = cpu_to_le64(src->ios[i]); + dst->merges[i] = cpu_to_le64(src->merges[i]); dst->sectors[i] = cpu_to_le64(src->sectors[i]); - dst->ticks[i] = cpu_to_le32(src->ticks[i]); + dst->ticks[i] = cpu_to_le64(src->ticks[i]); } - dst->io_ticks = cpu_to_le32(src->io_ticks); - dst->time_in_queue = cpu_to_le32(src->time_in_queue); + dst->io_ticks = cpu_to_le64(src->io_ticks); + dst->time_in_queue = cpu_to_le64(src->time_in_queue); dst->slavecount = cpu_to_le32(src->slavecount); dst->max_util.u.i = cpu_to_le64(fio_double_to_uint64(src->max_util.u.f)); } @@ -1198,14 +1198,14 @@ static void convert_dus(struct disk_util_stat *dst, struct disk_util_stat *src) strncpy((char *) dst->name, (char *) src->name, FIO_DU_NAME_SZ - 1); for (i = 0; i < 2; i++) { - dst->s.ios[i] = cpu_to_le32(src->s.ios[i]); - dst->s.merges[i] = cpu_to_le32(src->s.merges[i]); + dst->s.ios[i] = cpu_to_le64(src->s.ios[i]); + dst->s.merges[i] = cpu_to_le64(src->s.merges[i]); dst->s.sectors[i] = cpu_to_le64(src->s.sectors[i]); - dst->s.ticks[i] = cpu_to_le32(src->s.ticks[i]); + dst->s.ticks[i] = cpu_to_le64(src->s.ticks[i]); } - dst->s.io_ticks = cpu_to_le32(src->s.io_ticks); - dst->s.time_in_queue = cpu_to_le32(src->s.time_in_queue); + dst->s.io_ticks = cpu_to_le64(src->s.io_ticks); + dst->s.time_in_queue = cpu_to_le64(src->s.time_in_queue); dst->s.msec = cpu_to_le64(src->s.msec); } diff --git a/server.h b/server.h index 84a06a11..0a98bf5b 100644 --- a/server.h +++ b/server.h @@ -38,7 +38,7 @@ struct fio_net_cmd_reply { }; enum { - FIO_SERVER_VER = 39, + FIO_SERVER_VER = 40, FIO_SERVER_MAX_FRAGMENT_PDU = 1024, FIO_SERVER_MAX_CMD_MB = 2048, -- 2.25.1