Bump disk util stats from 32 to 64-bit values
authorJens Axboe <axboe@fb.com>
Mon, 1 Dec 2014 16:42:48 +0000 (09:42 -0700)
committerJens Axboe <axboe@fb.com>
Mon, 1 Dec 2014 16:42:48 +0000 (09:42 -0700)
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 <axboe@fb.com>
client.c
diskutil.c
diskutil.h
server.c
server.h

index 2c10c037602353da6e52541d0eed6874b0921176..3cb7c1c50a92f27706da48f5d4ce64ccb7ca6b59 100644 (file)
--- 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);
 }
 
index 51da8a089d5dc173cb1f2718c47e9adf6564f9fc..98ae2fe302008bf0c2b10cd55cb80c0a2b7327ae 100644 (file)
@@ -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], &sectors[0],
-                                       &dus->s.ticks[0], &dus->s.ios[1],
-                                       &dus->s.merges[1], &sectors[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],
+                               &sectors[0],
+                               (unsigned long long *) &dus->s.ticks[0],
+                               (unsigned long long *) &dus->s.ios[1],
+                               (unsigned long long *) &dus->s.merges[1],
+                               &sectors[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);
        }
 
        /*
index 8623fd723b723053c59337984208c5c7f3f57a8e..c0ae0ed057660ab23fc4f142e17bc725b5124c7e 100644 (file)
@@ -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;
 };
 
index c4ab906f74f38e579ee7eb3d838f95abbdef0fc5..ede291fab8f754c4459107d94e97f7ff4870b284 100644 (file)
--- 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);
 }
 
index 84a06a11fa620515de2afca90c3e1e925b4f9613..0a98bf5bb25e56c94402a981e575ff29620a45bd 100644 (file)
--- 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,