log: fix signedness issue
[fio.git] / blktrace.c
1 /*
2  * blktrace support code for fio
3  */
4 #include <stdio.h>
5 #include <stdlib.h>
6 #include <sys/ioctl.h>
7 #include <linux/fs.h>
8
9 #include "flist.h"
10 #include "fio.h"
11 #include "blktrace.h"
12 #include "blktrace_api.h"
13 #include "oslib/linux-dev-lookup.h"
14
15 #define TRACE_FIFO_SIZE 8192
16
17 /*
18  * fifo refill frontend, to avoid reading data in trace sized bites
19  */
20 static int refill_fifo(struct thread_data *td, struct fifo *fifo, int fd)
21 {
22         char buf[TRACE_FIFO_SIZE];
23         unsigned int total;
24         int ret;
25
26         total = sizeof(buf);
27         if (total > fifo_room(fifo))
28                 total = fifo_room(fifo);
29
30         ret = read(fd, buf, total);
31         if (ret < 0) {
32                 td_verror(td, errno, "read blktrace file");
33                 return -1;
34         }
35
36         if (ret > 0)
37                 ret = fifo_put(fifo, buf, ret);
38
39         dprint(FD_BLKTRACE, "refill: filled %d bytes\n", ret);
40         return ret;
41 }
42
43 /*
44  * Retrieve 'len' bytes from the fifo, refilling if necessary.
45  */
46 static int trace_fifo_get(struct thread_data *td, struct fifo *fifo, int fd,
47                           void *buf, unsigned int len)
48 {
49         if (fifo_len(fifo) < len) {
50                 int ret = refill_fifo(td, fifo, fd);
51
52                 if (ret < 0)
53                         return ret;
54         }
55
56         return fifo_get(fifo, buf, len);
57 }
58
59 /*
60  * Just discard the pdu by seeking past it.
61  */
62 static int discard_pdu(struct thread_data *td, struct fifo *fifo, int fd,
63                        struct blk_io_trace *t)
64 {
65         if (t->pdu_len == 0)
66                 return 0;
67
68         dprint(FD_BLKTRACE, "discard pdu len %u\n", t->pdu_len);
69         return trace_fifo_get(td, fifo, fd, NULL, t->pdu_len);
70 }
71
72 /*
73  * Check if this is a blktrace binary data file. We read a single trace
74  * into memory and check for the magic signature.
75  */
76 bool is_blktrace(const char *filename, int *need_swap)
77 {
78         struct blk_io_trace t;
79         int fd, ret;
80
81         fd = open(filename, O_RDONLY);
82         if (fd < 0)
83                 return false;
84
85         ret = read(fd, &t, sizeof(t));
86         close(fd);
87
88         if (ret < 0) {
89                 perror("read blktrace");
90                 return false;
91         } else if (ret != sizeof(t)) {
92                 log_err("fio: short read on blktrace file\n");
93                 return false;
94         }
95
96         if ((t.magic & 0xffffff00) == BLK_IO_TRACE_MAGIC) {
97                 *need_swap = 0;
98                 return true;
99         }
100
101         /*
102          * Maybe it needs to be endian swapped...
103          */
104         t.magic = fio_swap32(t.magic);
105         if ((t.magic & 0xffffff00) == BLK_IO_TRACE_MAGIC) {
106                 *need_swap = 1;
107                 return true;
108         }
109
110         return false;
111 }
112
113 #define FMINORBITS      20
114 #define FMINORMASK      ((1U << FMINORBITS) - 1)
115 #define FMAJOR(dev)     ((unsigned int) ((dev) >> FMINORBITS))
116 #define FMINOR(dev)     ((unsigned int) ((dev) & FMINORMASK))
117
118 static void trace_add_open_close_event(struct thread_data *td, int fileno, enum file_log_act action)
119 {
120         struct io_piece *ipo;
121
122         ipo = calloc(1, sizeof(*ipo));
123         init_ipo(ipo);
124
125         ipo->ddir = DDIR_INVAL;
126         ipo->fileno = fileno;
127         ipo->file_action = action;
128         flist_add_tail(&ipo->list, &td->io_log_list);
129 }
130
131 static int get_dev_blocksize(const char *dev, unsigned int *bs)
132 {
133         int fd;
134
135         fd = open(dev, O_RDONLY);
136         if (fd < 0)
137                 return 1;
138
139         if (ioctl(fd, BLKSSZGET, bs) < 0) {
140                 close(fd);
141                 return 1;
142         }
143
144         close(fd);
145         return 0;
146 }
147
148 static int trace_add_file(struct thread_data *td, __u32 device,
149                           unsigned int *bs)
150 {
151         static unsigned int last_maj, last_min, last_fileno, last_bs;
152         unsigned int maj = FMAJOR(device);
153         unsigned int min = FMINOR(device);
154         struct fio_file *f;
155         unsigned int i;
156         char dev[256];
157
158         if (last_maj == maj && last_min == min) {
159                 *bs = last_bs;
160                 return last_fileno;
161         }
162
163         last_maj = maj;
164         last_min = min;
165
166         /*
167          * check for this file in our list
168          */
169         for_each_file(td, f, i) {
170                 if (f->major == maj && f->minor == min) {
171                         last_fileno = f->fileno;
172                         last_bs = f->bs;
173                         goto out;
174                 }
175         }
176
177         strcpy(dev, "/dev");
178         if (blktrace_lookup_device(td->o.replay_redirect, dev, maj, min)) {
179                 unsigned int this_bs;
180                 int fileno;
181
182                 if (td->o.replay_redirect)
183                         dprint(FD_BLKTRACE, "device lookup: %d/%d\n overridden"
184                                         " with: %s\n", maj, min,
185                                         td->o.replay_redirect);
186                 else
187                         dprint(FD_BLKTRACE, "device lookup: %d/%d\n", maj, min);
188
189                 dprint(FD_BLKTRACE, "add devices %s\n", dev);
190                 fileno = add_file_exclusive(td, dev);
191
192                 if (get_dev_blocksize(dev, &this_bs))
193                         this_bs = 512;
194
195                 td->o.open_files++;
196                 td->files[fileno]->major = maj;
197                 td->files[fileno]->minor = min;
198                 td->files[fileno]->bs = this_bs;
199                 trace_add_open_close_event(td, fileno, FIO_LOG_OPEN_FILE);
200
201                 last_fileno = fileno;
202                 last_bs = this_bs;
203         }
204
205 out:
206         *bs = last_bs;
207         return last_fileno;
208 }
209
210 static void t_bytes_align(struct thread_options *o, struct blk_io_trace *t)
211 {
212         if (!o->replay_align)
213                 return;
214
215         t->bytes = (t->bytes + o->replay_align - 1) & ~(o->replay_align - 1);
216 }
217
218 /*
219  * Store blk_io_trace data in an ipo for later retrieval.
220  */
221 static void store_ipo(struct thread_data *td, unsigned long long offset,
222                       unsigned int bytes, int rw, unsigned long long ttime,
223                       int fileno, unsigned int bs)
224 {
225         struct io_piece *ipo;
226
227         ipo = calloc(1, sizeof(*ipo));
228         init_ipo(ipo);
229
230         ipo->offset = offset * bs;
231         if (td->o.replay_scale)
232                 ipo->offset = ipo->offset / td->o.replay_scale;
233         ipo_bytes_align(td->o.replay_align, ipo);
234         ipo->len = bytes;
235         ipo->delay = ttime / 1000;
236         if (rw)
237                 ipo->ddir = DDIR_WRITE;
238         else
239                 ipo->ddir = DDIR_READ;
240         ipo->fileno = fileno;
241
242         dprint(FD_BLKTRACE, "store ddir=%d, off=%llu, len=%lu, delay=%lu\n",
243                                                         ipo->ddir, ipo->offset,
244                                                         ipo->len, ipo->delay);
245         queue_io_piece(td, ipo);
246 }
247
248 static void handle_trace_notify(struct blk_io_trace *t)
249 {
250         switch (t->action) {
251         case BLK_TN_PROCESS:
252                 dprint(FD_BLKTRACE, "got process notify: %x, %d\n",
253                                 t->action, t->pid);
254                 break;
255         case BLK_TN_TIMESTAMP:
256                 dprint(FD_BLKTRACE, "got timestamp notify: %x, %d\n",
257                                 t->action, t->pid);
258                 break;
259         case BLK_TN_MESSAGE:
260                 break;
261         default:
262                 dprint(FD_BLKTRACE, "unknown trace act %x\n", t->action);
263                 break;
264         }
265 }
266
267 static void handle_trace_discard(struct thread_data *td,
268                                  struct blk_io_trace *t,
269                                  unsigned long long ttime,
270                                  unsigned long *ios, unsigned int *rw_bs)
271 {
272         struct io_piece *ipo;
273         unsigned int bs;
274         int fileno;
275
276         if (td->o.replay_skip & (1u << DDIR_TRIM))
277                 return;
278
279         ipo = calloc(1, sizeof(*ipo));
280         init_ipo(ipo);
281         fileno = trace_add_file(td, t->device, &bs);
282
283         ios[DDIR_TRIM]++;
284         if (t->bytes > rw_bs[DDIR_TRIM])
285                 rw_bs[DDIR_TRIM] = t->bytes;
286
287         td->o.size += t->bytes;
288
289         INIT_FLIST_HEAD(&ipo->list);
290
291         ipo->offset = t->sector * bs;
292         if (td->o.replay_scale)
293                 ipo->offset = ipo->offset / td->o.replay_scale;
294         ipo_bytes_align(td->o.replay_align, ipo);
295         ipo->len = t->bytes;
296         ipo->delay = ttime / 1000;
297         ipo->ddir = DDIR_TRIM;
298         ipo->fileno = fileno;
299
300         dprint(FD_BLKTRACE, "store discard, off=%llu, len=%lu, delay=%lu\n",
301                                                         ipo->offset, ipo->len,
302                                                         ipo->delay);
303         queue_io_piece(td, ipo);
304 }
305
306 static void handle_trace_fs(struct thread_data *td, struct blk_io_trace *t,
307                             unsigned long long ttime, unsigned long *ios,
308                             unsigned int *rw_bs)
309 {
310         unsigned int bs;
311         int rw;
312         int fileno;
313
314         fileno = trace_add_file(td, t->device, &bs);
315
316         rw = (t->action & BLK_TC_ACT(BLK_TC_WRITE)) != 0;
317
318         if (rw) {
319                 if (td->o.replay_skip & (1u << DDIR_WRITE))
320                         return;
321         } else {
322                 if (td->o.replay_skip & (1u << DDIR_READ))
323                         return;
324         }
325
326         assert(t->bytes);
327
328         if (t->bytes > rw_bs[rw])
329                 rw_bs[rw] = t->bytes;
330
331         ios[rw]++;
332         td->o.size += t->bytes;
333         store_ipo(td, t->sector, t->bytes, rw, ttime, fileno, bs);
334 }
335
336 static void handle_trace_flush(struct thread_data *td, struct blk_io_trace *t,
337                                unsigned long long ttime, unsigned long *ios)
338 {
339         struct io_piece *ipo;
340         unsigned int bs;
341         int fileno;
342
343         if (td->o.replay_skip & (1u << DDIR_SYNC))
344                 return;
345
346         ipo = calloc(1, sizeof(*ipo));
347         init_ipo(ipo);
348         fileno = trace_add_file(td, t->device, &bs);
349
350         ipo->delay = ttime / 1000;
351         ipo->ddir = DDIR_SYNC;
352         ipo->fileno = fileno;
353
354         ios[DDIR_SYNC]++;
355         dprint(FD_BLKTRACE, "store flush delay=%lu\n", ipo->delay);
356         queue_io_piece(td, ipo);
357 }
358
359 /*
360  * We only care for queue traces, most of the others are side effects
361  * due to internal workings of the block layer.
362  */
363 static void handle_trace(struct thread_data *td, struct blk_io_trace *t,
364                          unsigned long *ios, unsigned int *bs)
365 {
366         static unsigned long long last_ttime;
367         unsigned long long delay = 0;
368
369         if ((t->action & 0xffff) != __BLK_TA_QUEUE)
370                 return;
371
372         if (!(t->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
373                 if (!last_ttime || td->o.no_stall)
374                         delay = 0;
375                 else if (td->o.replay_time_scale == 100)
376                         delay = t->time - last_ttime;
377                 else {
378                         double tmp = t->time - last_ttime;
379                         double scale;
380
381                         scale = (double) 100.0 / (double) td->o.replay_time_scale;
382                         tmp *= scale;
383                         delay = tmp;
384                 }
385                 last_ttime = t->time;
386         }
387
388         t_bytes_align(&td->o, t);
389
390         if (t->action & BLK_TC_ACT(BLK_TC_NOTIFY))
391                 handle_trace_notify(t);
392         else if (t->action & BLK_TC_ACT(BLK_TC_DISCARD))
393                 handle_trace_discard(td, t, delay, ios, bs);
394         else if (t->action & BLK_TC_ACT(BLK_TC_FLUSH))
395                 handle_trace_flush(td, t, delay, ios);
396         else
397                 handle_trace_fs(td, t, delay, ios, bs);
398 }
399
400 static void byteswap_trace(struct blk_io_trace *t)
401 {
402         t->magic = fio_swap32(t->magic);
403         t->sequence = fio_swap32(t->sequence);
404         t->time = fio_swap64(t->time);
405         t->sector = fio_swap64(t->sector);
406         t->bytes = fio_swap32(t->bytes);
407         t->action = fio_swap32(t->action);
408         t->pid = fio_swap32(t->pid);
409         t->device = fio_swap32(t->device);
410         t->cpu = fio_swap32(t->cpu);
411         t->error = fio_swap16(t->error);
412         t->pdu_len = fio_swap16(t->pdu_len);
413 }
414
415 static bool t_is_write(struct blk_io_trace *t)
416 {
417         return (t->action & BLK_TC_ACT(BLK_TC_WRITE | BLK_TC_DISCARD)) != 0;
418 }
419
420 static enum fio_ddir t_get_ddir(struct blk_io_trace *t)
421 {
422         if (t->action & BLK_TC_ACT(BLK_TC_READ))
423                 return DDIR_READ;
424         else if (t->action & BLK_TC_ACT(BLK_TC_WRITE))
425                 return DDIR_WRITE;
426         else if (t->action & BLK_TC_ACT(BLK_TC_DISCARD))
427                 return DDIR_TRIM;
428
429         return DDIR_INVAL;
430 }
431
432 static void depth_inc(struct blk_io_trace *t, int *depth)
433 {
434         enum fio_ddir ddir;
435
436         ddir = t_get_ddir(t);
437         if (ddir != DDIR_INVAL)
438                 depth[ddir]++;
439 }
440
441 static void depth_dec(struct blk_io_trace *t, int *depth)
442 {
443         enum fio_ddir ddir;
444
445         ddir = t_get_ddir(t);
446         if (ddir != DDIR_INVAL)
447                 depth[ddir]--;
448 }
449
450 static void depth_end(struct blk_io_trace *t, int *this_depth, int *depth)
451 {
452         enum fio_ddir ddir = DDIR_INVAL;
453
454         ddir = t_get_ddir(t);
455         if (ddir != DDIR_INVAL) {
456                 depth[ddir] = max(depth[ddir], this_depth[ddir]);
457                 this_depth[ddir] = 0;
458         }
459 }
460
461 /*
462  * Load a blktrace file by reading all the blk_io_trace entries, and storing
463  * them as io_pieces like the fio text version would do.
464  */
465 bool load_blktrace(struct thread_data *td, const char *filename, int need_swap)
466 {
467         struct blk_io_trace t;
468         unsigned long ios[DDIR_RWDIR_SYNC_CNT] = { };
469         unsigned int rw_bs[DDIR_RWDIR_CNT] = { };
470         unsigned long skipped_writes;
471         struct fifo *fifo;
472         int fd, i, old_state, max_depth;
473         struct fio_file *f;
474         int this_depth[DDIR_RWDIR_CNT] = { };
475         int depth[DDIR_RWDIR_CNT] = { };
476
477         fd = open(filename, O_RDONLY);
478         if (fd < 0) {
479                 td_verror(td, errno, "open blktrace file");
480                 return false;
481         }
482
483         fifo = fifo_alloc(TRACE_FIFO_SIZE);
484
485         old_state = td_bump_runstate(td, TD_SETTING_UP);
486
487         td->o.size = 0;
488         skipped_writes = 0;
489         do {
490                 int ret = trace_fifo_get(td, fifo, fd, &t, sizeof(t));
491
492                 if (ret < 0)
493                         goto err;
494                 else if (!ret)
495                         break;
496                 else if (ret < (int) sizeof(t)) {
497                         log_err("fio: short fifo get\n");
498                         break;
499                 }
500
501                 if (need_swap)
502                         byteswap_trace(&t);
503
504                 if ((t.magic & 0xffffff00) != BLK_IO_TRACE_MAGIC) {
505                         log_err("fio: bad magic in blktrace data: %x\n",
506                                                                 t.magic);
507                         goto err;
508                 }
509                 if ((t.magic & 0xff) != BLK_IO_TRACE_VERSION) {
510                         log_err("fio: bad blktrace version %d\n",
511                                                                 t.magic & 0xff);
512                         goto err;
513                 }
514                 ret = discard_pdu(td, fifo, fd, &t);
515                 if (ret < 0) {
516                         td_verror(td, ret, "blktrace lseek");
517                         goto err;
518                 } else if (t.pdu_len != ret) {
519                         log_err("fio: discarded %d of %d\n", ret, t.pdu_len);
520                         goto err;
521                 }
522                 if ((t.action & BLK_TC_ACT(BLK_TC_NOTIFY)) == 0) {
523                         if ((t.action & 0xffff) == __BLK_TA_QUEUE)
524                                 depth_inc(&t, this_depth);
525                         else if (((t.action & 0xffff) == __BLK_TA_BACKMERGE) ||
526                                 ((t.action & 0xffff) == __BLK_TA_FRONTMERGE))
527                                 depth_dec(&t, this_depth);
528                         else if ((t.action & 0xffff) == __BLK_TA_COMPLETE)
529                                 depth_end(&t, this_depth, depth);
530
531                         if (t_is_write(&t) && read_only) {
532                                 skipped_writes++;
533                                 continue;
534                         }
535                 }
536
537                 handle_trace(td, &t, ios, rw_bs);
538         } while (1);
539
540         for_each_file(td, f, i)
541                 trace_add_open_close_event(td, f->fileno, FIO_LOG_CLOSE_FILE);
542
543         fifo_free(fifo);
544         close(fd);
545
546         td_restore_runstate(td, old_state);
547
548         if (!td->files_index) {
549                 log_err("fio: did not find replay device(s)\n");
550                 return false;
551         }
552
553         /*
554          * For stacked devices, we don't always get a COMPLETE event so
555          * the depth grows to insane values. Limit it to something sane(r).
556          */
557         max_depth = 0;
558         for (i = 0; i < DDIR_RWDIR_CNT; i++) {
559                 if (depth[i] > 1024)
560                         depth[i] = 1024;
561                 else if (!depth[i] && ios[i])
562                         depth[i] = 1;
563                 max_depth = max(depth[i], max_depth);
564         }
565
566         if (skipped_writes)
567                 log_err("fio: %s skips replay of %lu writes due to read-only\n",
568                                                 td->o.name, skipped_writes);
569
570         if (!ios[DDIR_READ] && !ios[DDIR_WRITE] && !ios[DDIR_TRIM] &&
571             !ios[DDIR_SYNC]) {
572                 log_err("fio: found no ios in blktrace data\n");
573                 return false;
574         } else if (ios[DDIR_READ] && !ios[DDIR_WRITE]) {
575                 td->o.td_ddir = TD_DDIR_READ;
576                 td->o.max_bs[DDIR_READ] = rw_bs[DDIR_READ];
577         } else if (!ios[DDIR_READ] && ios[DDIR_WRITE]) {
578                 td->o.td_ddir = TD_DDIR_WRITE;
579                 td->o.max_bs[DDIR_WRITE] = rw_bs[DDIR_WRITE];
580         } else {
581                 td->o.td_ddir = TD_DDIR_RW;
582                 td->o.max_bs[DDIR_READ] = rw_bs[DDIR_READ];
583                 td->o.max_bs[DDIR_WRITE] = rw_bs[DDIR_WRITE];
584                 td->o.max_bs[DDIR_TRIM] = rw_bs[DDIR_TRIM];
585         }
586
587         /*
588          * We need to do direct/raw ios to the device, to avoid getting
589          * read-ahead in our way. But only do so if the minimum block size
590          * is a multiple of 4k, otherwise we don't know if it's safe to do so.
591          */
592         if (!fio_option_is_set(&td->o, odirect) && !(td_min_bs(td) & 4095))
593                 td->o.odirect = 1;
594
595         /*
596          * If depth wasn't manually set, use probed depth
597          */
598         if (!fio_option_is_set(&td->o, iodepth))
599                 td->o.iodepth = td->o.iodepth_low = max_depth;
600
601         return true;
602 err:
603         close(fd);
604         fifo_free(fifo);
605         return false;
606 }