blktrace: various bug fixes and improvements
authorJens Axboe <axboe@fb.com>
Mon, 14 Jul 2014 13:07:11 +0000 (15:07 +0200)
committerJens Axboe <axboe@fb.com>
Mon, 14 Jul 2014 13:07:11 +0000 (15:07 +0200)
- Use the normal debug logging for notify events, as they are expected
  to happen.

- Correct a bug where a workload is considered mixed, even if it is
  only reads (note: just cosmetical, no writes were issued by fio).

- Handle trim more appropriately - fio supports it as a separate
  'data direction', so handle it as such.

- Fix a bug in the delay accounting, causing blktrace to not replay
  correctly. This could cause either too fast replays, or replays
  that would delay way too much.

- Consider TRIMs as writes, as far as --readonly being set is
  concerned.

- Don't consider < 100 usec delays noise, fio can do this quite
  accurately.

Signed-off-by: Jens Axboe <axboe@fb.com>
blktrace.c
iolog.c

index 29eed50c391c422da566eb063cb2bc4863bd19a1..3c23b973d971fb0f75011c54f7d616c64a42e931 100644 (file)
@@ -260,11 +260,11 @@ static void handle_trace_notify(struct blk_io_trace *t)
 {
        switch (t->action) {
        case BLK_TN_PROCESS:
-               log_info("blktrace: got process notify: %x, %d\n",
+               dprint(FD_BLKTRACE, "got process notify: %x, %d\n",
                                t->action, t->pid);
                break;
        case BLK_TN_TIMESTAMP:
-               log_info("blktrace: got timestamp notify: %x, %d\n",
+               dprint(FD_BLKTRACE, "got timestamp notify: %x, %d\n",
                                t->action, t->pid);
                break;
        case BLK_TN_MESSAGE:
@@ -275,8 +275,10 @@ static void handle_trace_notify(struct blk_io_trace *t)
        }
 }
 
-static void handle_trace_discard(struct thread_data *td, struct blk_io_trace *t,
-                                unsigned long long ttime, unsigned long *ios)
+static void handle_trace_discard(struct thread_data *td,
+                                struct blk_io_trace *t,
+                                unsigned long long ttime,
+                                unsigned long *ios, unsigned int *bs)
 {
        struct io_piece *ipo = malloc(sizeof(*ipo));
        int fileno;
@@ -284,7 +286,10 @@ static void handle_trace_discard(struct thread_data *td, struct blk_io_trace *t,
        init_ipo(ipo);
        fileno = trace_add_file(td, t->device);
 
-       ios[DDIR_WRITE]++;
+       ios[DDIR_TRIM]++;
+       if (t->bytes > bs[DDIR_TRIM])
+               bs[DDIR_TRIM] = t->bytes;
+
        td->o.size += t->bytes;
 
        memset(ipo, 0, sizeof(*ipo));
@@ -329,20 +334,30 @@ static void handle_trace_fs(struct thread_data *td, struct blk_io_trace *t,
  * due to internal workings of the block layer.
  */
 static void handle_trace(struct thread_data *td, struct blk_io_trace *t,
-                        unsigned long long ttime, unsigned long *ios,
-                        unsigned int *bs)
+                        unsigned long *ios, unsigned int *bs)
 {
+       static unsigned long long last_ttime;
+       unsigned long long delay;
+
        if ((t->action & 0xffff) != __BLK_TA_QUEUE)
                return;
-       if (t->action & BLK_TC_ACT(BLK_TC_PC))
-               return;
+
+       if (!(t->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
+               if (!last_ttime || td->o.no_stall) {
+                       last_ttime = t->time;
+                       delay = 0;
+               } else {
+                       delay = t->time - last_ttime;
+                       last_ttime = t->time;
+               }
+       }
 
        if (t->action & BLK_TC_ACT(BLK_TC_NOTIFY))
                handle_trace_notify(t);
        else if (t->action & BLK_TC_ACT(BLK_TC_DISCARD))
-               handle_trace_discard(td, t, ttime, ios);
+               handle_trace_discard(td, t, delay, ios, bs);
        else
-               handle_trace_fs(td, t, ttime, ios, bs);
+               handle_trace_fs(td, t, delay, ios, bs);
 }
 
 static void byteswap_trace(struct blk_io_trace *t)
@@ -360,17 +375,20 @@ static void byteswap_trace(struct blk_io_trace *t)
        t->pdu_len = fio_swap16(t->pdu_len);
 }
 
+static int t_is_write(struct blk_io_trace *t)
+{
+       return (t->action & BLK_TC_ACT(BLK_TC_WRITE | BLK_TC_DISCARD)) != 0;
+}
+
 /*
  * Load a blktrace file by reading all the blk_io_trace entries, and storing
  * them as io_pieces like the fio text version would do.
  */
 int load_blktrace(struct thread_data *td, const char *filename, int need_swap)
 {
-       unsigned long long ttime, delay;
        struct blk_io_trace t;
-       unsigned long ios[2], skipped_writes;
-       unsigned int cpu;
-       unsigned int rw_bs[2];
+       unsigned long ios[DDIR_RWDIR_CNT], skipped_writes;
+       unsigned int rw_bs[DDIR_RWDIR_CNT];
        struct fifo *fifo;
        int fd, i, old_state;
        struct fio_file *f;
@@ -388,8 +406,6 @@ int load_blktrace(struct thread_data *td, const char *filename, int need_swap)
 
        td->o.size = 0;
 
-       cpu = 0;
-       ttime = 0;
        ios[0] = ios[1] = 0;
        rw_bs[0] = rw_bs[1] = 0;
        skipped_writes = 0;
@@ -434,33 +450,14 @@ int load_blktrace(struct thread_data *td, const char *filename, int need_swap)
                                depth = max(depth, this_depth);
                                this_depth = 0;
                        }
-                       if (!ttime) {
-                               ttime = t.time;
-                               cpu = t.cpu;
-                       }
 
-                       delay = 0;
-                       if (cpu == t.cpu)
-                               delay = t.time - ttime;
-                       if ((t.action & BLK_TC_ACT(BLK_TC_WRITE)) && read_only)
+                       if (t_is_write(&t) && read_only) {
                                skipped_writes++;
-                       else {
-                               /*
-                                * set delay to zero if no_stall enabled for
-                                * fast replay
-                                */
-                               if (td->o.no_stall)
-                                       delay = 0;
-
-                               handle_trace(td, &t, delay, ios, rw_bs);
+                               continue;
                        }
-
-                       ttime = t.time;
-                       cpu = t.cpu;
-               } else {
-                       delay = 0;
-                       handle_trace(td, &t, delay, ios, rw_bs);
                }
+
+               handle_trace(td, &t, ios, rw_bs);
        } while (1);
 
        for (i = 0; i < td->files_index; i++) {
@@ -492,7 +489,7 @@ int load_blktrace(struct thread_data *td, const char *filename, int need_swap)
        if (!ios[DDIR_READ] && !ios[DDIR_WRITE]) {
                log_err("fio: found no ios in blktrace data\n");
                return 1;
-       } else if (ios[DDIR_READ] && !ios[DDIR_READ]) {
+       } else if (ios[DDIR_READ] && !ios[DDIR_WRITE]) {
                td->o.td_ddir = TD_DDIR_READ;
                td->o.max_bs[DDIR_READ] = rw_bs[DDIR_READ];
        } else if (!ios[DDIR_READ] && ios[DDIR_WRITE]) {
@@ -502,6 +499,7 @@ int load_blktrace(struct thread_data *td, const char *filename, int need_swap)
                td->o.td_ddir = TD_DDIR_RW;
                td->o.max_bs[DDIR_READ] = rw_bs[DDIR_READ];
                td->o.max_bs[DDIR_WRITE] = rw_bs[DDIR_WRITE];
+               td->o.max_bs[DDIR_TRIM] = rw_bs[DDIR_TRIM];
        }
 
        /*
diff --git a/iolog.c b/iolog.c
index 100b5d79eb14001cdbdddda7cc17c337765f0b52..70ccfba482204e123ebfbda8187977486f92b8eb 100644 (file)
--- a/iolog.c
+++ b/iolog.c
@@ -73,12 +73,6 @@ static void iolog_delay(struct thread_data *td, unsigned long delay)
 
        delay -= usec;
 
-       /*
-        * less than 100 usec delay, just regard it as noise
-        */
-       if (delay < 100)
-               return;
-
        while (delay && !td->terminate) {
                this_delay = delay;
                if (this_delay > 500000)