iowatcher: Only hash IOs if there are completion or issue events
[blktrace.git] / iowatcher / blkparse.c
CommitLineData
9e066e23
CM
1/*
2 * Copyright (C) 2012 Fusion-io
3 *
4 * This program is free software; you can redistribute it and/or
5 * modify it under the terms of the GNU General Public
6 * License v2 as published by the Free Software Foundation.
7 *
8 * This program is distributed in the hope that it will be useful,
9 * but WITHOUT ANY WARRANTY; without even the implied warranty of
10 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
11 * GNU General Public License for more details.
12 *
13 * You should have received a copy of the GNU General Public License
14 * along with this program; if not, write to the Free Software
15 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
16 *
17 * Parts of this file were imported from Jens Axboe's blktrace sources (also GPL)
18 */
19#include <sys/types.h>
20#include <sys/stat.h>
21#include <fcntl.h>
22#include <unistd.h>
23#include <stdlib.h>
24#include <stdio.h>
25#include <math.h>
26#include <inttypes.h>
27#include <string.h>
28#include <asm/types.h>
29#include <errno.h>
30#include <sys/mman.h>
31#include <time.h>
32#include <math.h>
33
34#include "plot.h"
35#include "blkparse.h"
36#include "list.h"
37#include "tracers.h"
38
39#define IO_HASH_TABLE_BITS 11
40#define IO_HASH_TABLE_SIZE (1 << IO_HASH_TABLE_BITS)
41static struct list_head io_hash_table[IO_HASH_TABLE_SIZE];
42static u64 ios_in_flight = 0;
43
0a43b43f
JK
44#define PROCESS_HASH_TABLE_BITS 7
45#define PROCESS_HASH_TABLE_SIZE (1 << PROCESS_HASH_TABLE_BITS)
46static struct list_head process_hash_table[PROCESS_HASH_TABLE_SIZE];
47
f2e40ddd 48extern int plot_io_action;
0a43b43f 49extern int io_per_process;
9e066e23
CM
50
51/*
52 * Trace categories
53 */
54enum {
55 BLK_TC_READ = 1 << 0, /* reads */
56 BLK_TC_WRITE = 1 << 1, /* writes */
57 BLK_TC_FLUSH = 1 << 2, /* flush */
58 BLK_TC_SYNC = 1 << 3, /* sync */
59 BLK_TC_QUEUE = 1 << 4, /* queueing/merging */
60 BLK_TC_REQUEUE = 1 << 5, /* requeueing */
61 BLK_TC_ISSUE = 1 << 6, /* issue */
62 BLK_TC_COMPLETE = 1 << 7, /* completions */
63 BLK_TC_FS = 1 << 8, /* fs requests */
64 BLK_TC_PC = 1 << 9, /* pc requests */
65 BLK_TC_NOTIFY = 1 << 10, /* special message */
66 BLK_TC_AHEAD = 1 << 11, /* readahead */
67 BLK_TC_META = 1 << 12, /* metadata */
68 BLK_TC_DISCARD = 1 << 13, /* discard requests */
69 BLK_TC_DRV_DATA = 1 << 14, /* binary driver data */
70 BLK_TC_FUA = 1 << 15, /* fua requests */
71
72 BLK_TC_END = 1 << 15, /* we've run out of bits! */
73};
74
75#define BLK_TC_SHIFT (16)
76#define BLK_TC_ACT(act) ((act) << BLK_TC_SHIFT)
77#define BLK_DATADIR(a) (((a) >> BLK_TC_SHIFT) & (BLK_TC_READ | BLK_TC_WRITE))
78
79/*
80 * Basic trace actions
81 */
82enum {
83 __BLK_TA_QUEUE = 1, /* queued */
84 __BLK_TA_BACKMERGE, /* back merged to existing rq */
85 __BLK_TA_FRONTMERGE, /* front merge to existing rq */
86 __BLK_TA_GETRQ, /* allocated new request */
87 __BLK_TA_SLEEPRQ, /* sleeping on rq allocation */
88 __BLK_TA_REQUEUE, /* request requeued */
89 __BLK_TA_ISSUE, /* sent to driver */
90 __BLK_TA_COMPLETE, /* completed by driver */
91 __BLK_TA_PLUG, /* queue was plugged */
92 __BLK_TA_UNPLUG_IO, /* queue was unplugged by io */
93 __BLK_TA_UNPLUG_TIMER, /* queue was unplugged by timer */
94 __BLK_TA_INSERT, /* insert request */
95 __BLK_TA_SPLIT, /* bio was split */
96 __BLK_TA_BOUNCE, /* bio was bounced */
97 __BLK_TA_REMAP, /* bio was remapped */
98 __BLK_TA_ABORT, /* request aborted */
99 __BLK_TA_DRV_DATA, /* binary driver data */
100};
101
1582ecc9
JK
102#define BLK_TA_MASK ((1 << BLK_TC_SHIFT) - 1)
103
9e066e23
CM
104/*
105 * Notify events.
106 */
107enum blktrace_notify {
108 __BLK_TN_PROCESS = 0, /* establish pid/name mapping */
109 __BLK_TN_TIMESTAMP, /* include system clock */
110 __BLK_TN_MESSAGE, /* Character string message */
111};
112
113/*
114 * Trace actions in full. Additionally, read or write is masked
115 */
116#define BLK_TA_QUEUE (__BLK_TA_QUEUE | BLK_TC_ACT(BLK_TC_QUEUE))
117#define BLK_TA_BACKMERGE (__BLK_TA_BACKMERGE | BLK_TC_ACT(BLK_TC_QUEUE))
118#define BLK_TA_FRONTMERGE (__BLK_TA_FRONTMERGE | BLK_TC_ACT(BLK_TC_QUEUE))
119#define BLK_TA_GETRQ (__BLK_TA_GETRQ | BLK_TC_ACT(BLK_TC_QUEUE))
120#define BLK_TA_SLEEPRQ (__BLK_TA_SLEEPRQ | BLK_TC_ACT(BLK_TC_QUEUE))
121#define BLK_TA_REQUEUE (__BLK_TA_REQUEUE | BLK_TC_ACT(BLK_TC_REQUEUE))
122#define BLK_TA_ISSUE (__BLK_TA_ISSUE | BLK_TC_ACT(BLK_TC_ISSUE))
123#define BLK_TA_COMPLETE (__BLK_TA_COMPLETE| BLK_TC_ACT(BLK_TC_COMPLETE))
124#define BLK_TA_PLUG (__BLK_TA_PLUG | BLK_TC_ACT(BLK_TC_QUEUE))
125#define BLK_TA_UNPLUG_IO (__BLK_TA_UNPLUG_IO | BLK_TC_ACT(BLK_TC_QUEUE))
126#define BLK_TA_UNPLUG_TIMER (__BLK_TA_UNPLUG_TIMER | BLK_TC_ACT(BLK_TC_QUEUE))
127#define BLK_TA_INSERT (__BLK_TA_INSERT | BLK_TC_ACT(BLK_TC_QUEUE))
128#define BLK_TA_SPLIT (__BLK_TA_SPLIT)
129#define BLK_TA_BOUNCE (__BLK_TA_BOUNCE)
130#define BLK_TA_REMAP (__BLK_TA_REMAP | BLK_TC_ACT(BLK_TC_QUEUE))
131#define BLK_TA_ABORT (__BLK_TA_ABORT | BLK_TC_ACT(BLK_TC_QUEUE))
132#define BLK_TA_DRV_DATA (__BLK_TA_DRV_DATA | BLK_TC_ACT(BLK_TC_DRV_DATA))
133
134#define BLK_TN_PROCESS (__BLK_TN_PROCESS | BLK_TC_ACT(BLK_TC_NOTIFY))
135#define BLK_TN_TIMESTAMP (__BLK_TN_TIMESTAMP | BLK_TC_ACT(BLK_TC_NOTIFY))
136#define BLK_TN_MESSAGE (__BLK_TN_MESSAGE | BLK_TC_ACT(BLK_TC_NOTIFY))
137
138#define BLK_IO_TRACE_MAGIC 0x65617400
139#define BLK_IO_TRACE_VERSION 0x07
140/*
141 * The trace itself
142 */
143struct blk_io_trace {
144 __u32 magic; /* MAGIC << 8 | version */
145 __u32 sequence; /* event number */
146 __u64 time; /* in nanoseconds */
147 __u64 sector; /* disk offset */
148 __u32 bytes; /* transfer length */
149 __u32 action; /* what happened */
150 __u32 pid; /* who did it */
151 __u32 device; /* device identifier (dev_t) */
152 __u32 cpu; /* on what cpu did it happen */
153 __u16 error; /* completion error */
154 __u16 pdu_len; /* length of data after this trace */
155};
156
157struct pending_io {
158 /* sector offset of this IO */
159 u64 sector;
160
161 /* time this IO was dispatched */
162 u64 dispatch_time;
163 /* time this IO was finished */
164 u64 completion_time;
165 struct list_head hash_list;
0a43b43f
JK
166 /* process which queued this IO */
167 u32 pid;
168};
169
170struct pid_map {
171 struct list_head hash_list;
172 u32 pid;
173 int index;
174 char name[0];
9e066e23
CM
175};
176
177#define MINORBITS 20
178#define MINORMASK ((1 << MINORBITS) - 1)
179#define SECONDS(x) ((unsigned long long)(x) / 1000000000)
180#define NANO_SECONDS(x) ((unsigned long long)(x) % 1000000000)
181#define DOUBLE_TO_NANO_ULL(d) ((unsigned long long)((d) * 1000000000))
182#define CHECK_MAGIC(t) (((t)->magic & 0xffffff00) == BLK_IO_TRACE_MAGIC)
183
184void init_io_hash_table(void)
185{
186 int i;
187 struct list_head *head;
188
189 for (i = 0; i < IO_HASH_TABLE_SIZE; i++) {
190 head = io_hash_table + i;
191 INIT_LIST_HEAD(head);
192 }
193}
194
195/* taken from the kernel hash.h */
196static inline u64 hash_sector(u64 val)
197{
198 u64 hash = val;
199
200 /* Sigh, gcc can't optimise this alone like it does for 32 bits. */
201 u64 n = hash;
202 n <<= 18;
203 hash -= n;
204 n <<= 33;
205 hash -= n;
206 n <<= 3;
207 hash += n;
208 n <<= 3;
209 hash -= n;
210 n <<= 4;
211 hash += n;
212 n <<= 2;
213 hash += n;
214
215 /* High bits are more random, so use them. */
216 return hash >> (64 - IO_HASH_TABLE_BITS);
217}
218
0a43b43f 219static int io_hash_table_insert(struct pending_io *ins_pio)
9e066e23
CM
220{
221 u64 sector = ins_pio->sector;
222 int slot = hash_sector(sector);
223 struct list_head *head;
224 struct pending_io *pio;
225
226 head = io_hash_table + slot;
227 list_for_each_entry(pio, head, hash_list) {
228 if (pio->sector == sector)
229 return -EEXIST;
230 }
231 list_add_tail(&ins_pio->hash_list, head);
232 return 0;
233}
234
0a43b43f 235static struct pending_io *io_hash_table_search(u64 sector)
9e066e23
CM
236{
237 int slot = hash_sector(sector);
238 struct list_head *head;
239 struct pending_io *pio;
240
241 head = io_hash_table + slot;
242 list_for_each_entry(pio, head, hash_list) {
243 if (pio->sector == sector)
244 return pio;
245 }
246 return NULL;
247}
248
0a43b43f 249static int hash_queued_io(struct blk_io_trace *io)
9e066e23
CM
250{
251 struct pending_io *pio;
252 int ret;
253
254 pio = calloc(1, sizeof(*pio));
255 pio->sector = io->sector;
0a43b43f 256 pio->pid = io->pid;
9e066e23 257
0a43b43f
JK
258 ret = io_hash_table_insert(pio);
259 if (ret < 0) {
260 /* crud, the IO is there already */
9e066e23 261 free(pio);
0a43b43f 262 return ret;
9e066e23 263 }
0a43b43f
JK
264 return 0;
265}
266
854a1f24 267static struct pending_io *hash_dispatched_io(struct blk_io_trace *io)
0a43b43f
JK
268{
269 struct pending_io *pio;
270
271 pio = io_hash_table_search(io->sector);
854a1f24
CM
272 if (!pio)
273 hash_queued_io(io);
0a43b43f 274 pio->dispatch_time = io->time;
854a1f24 275 return pio;
9e066e23
CM
276}
277
278static struct pending_io *hash_completed_io(struct blk_io_trace *io)
279{
280 struct pending_io *pio;
281
0a43b43f 282 pio = io_hash_table_search(io->sector);
9e066e23
CM
283
284 if (!pio)
285 return NULL;
286 return pio;
287}
288
0a43b43f
JK
289void init_process_hash_table(void)
290{
291 int i;
292 struct list_head *head;
293
294 for (i = 0; i < PROCESS_HASH_TABLE_SIZE; i++) {
295 head = process_hash_table + i;
296 INIT_LIST_HEAD(head);
297 }
298}
299
300static u32 hash_pid(u32 pid)
301{
302 u32 hash = pid;
303
304 hash ^= pid >> 3;
305 hash ^= pid >> 3;
306 hash ^= pid >> 4;
307 hash ^= pid >> 6;
308 return (hash & (PROCESS_HASH_TABLE_SIZE - 1));
309}
310
311static struct pid_map *process_hash_search(u32 pid)
312{
313 int slot = hash_pid(pid);
314 struct list_head *head;
315 struct pid_map *pm;
316
317 head = process_hash_table + slot;
318 list_for_each_entry(pm, head, hash_list) {
319 if (pm->pid == pid)
320 return pm;
321 }
322 return NULL;
323}
324
325static struct pid_map *process_hash_insert(u32 pid, char *name)
326{
327 int slot = hash_pid(pid);
328 struct pid_map *pm;
329 int old_index = 0;
330 char buf[16];
331
332 pm = process_hash_search(pid);
333 if (pm) {
334 /* Entry exists and name shouldn't be changed? */
335 if (!name || !strcmp(name, pm->name))
336 return pm;
337 list_del(&pm->hash_list);
338 old_index = pm->index;
339 free(pm);
340 }
341 if (!name) {
342 sprintf(buf, "[%u]", pid);
343 name = buf;
344 }
345 pm = malloc(sizeof(struct pid_map) + strlen(name) + 1);
346 pm->pid = pid;
347 pm->index = old_index;
348 strcpy(pm->name, name);
349 list_add_tail(&pm->hash_list, process_hash_table + slot);
350
351 return pm;
352}
353
9e066e23
CM
354static void handle_notify(struct trace *trace)
355{
356 struct blk_io_trace *io = trace->io;
357 void *payload = (char *)io + sizeof(*io);
358 u32 two32[2];
359
0a43b43f
JK
360 if (io->action == BLK_TN_PROCESS) {
361 if (io_per_process)
362 process_hash_insert(io->pid, payload);
363 return;
364 }
9e066e23
CM
365
366 if (io->action != BLK_TN_TIMESTAMP)
367 return;
368
369 if (io->pdu_len != sizeof(two32))
370 return;
371
372 memcpy(two32, payload, sizeof(two32));
373 trace->start_timestamp = io->time;
374 trace->abs_start_time.tv_sec = two32[0];
375 trace->abs_start_time.tv_nsec = two32[1];
376 if (trace->abs_start_time.tv_nsec < 0) {
377 trace->abs_start_time.tv_sec--;
378 trace->abs_start_time.tv_nsec += 1000000000;
379 }
380}
381
382int next_record(struct trace *trace)
383{
384 int skip = trace->io->pdu_len;
385 u64 offset;
386
387 trace->cur += sizeof(*trace->io) + skip;
388 offset = trace->cur - trace->start;
389 if (offset >= trace->len)
390 return 1;
391
392 trace->io = (struct blk_io_trace *)trace->cur;
393 return 0;
394}
395
396void first_record(struct trace *trace)
397{
398 trace->cur = trace->start;
399 trace->io = (struct blk_io_trace *)trace->cur;
400}
401
bfb0e441
CM
402int is_io_event(struct blk_io_trace *test)
403{
404 char *message;
405 if (!(test->action & BLK_TC_ACT(BLK_TC_NOTIFY)))
406 return 1;
407 if (test->action == BLK_TN_MESSAGE) {
408 int len = test->pdu_len;
409 if (len < 3)
410 return 0;
411 message = (char *)(test + 1);
412 if (strncmp(message, "fio ", 4) == 0) {
413 return 1;
414 }
415 }
416 return 0;
417}
418
9e066e23
CM
419u64 find_last_time(struct trace *trace)
420{
421 char *p = trace->start + trace->len;
422 struct blk_io_trace *test;
423 int search_len = 0;
424 u64 found = 0;
425
426 if (trace->len < sizeof(*trace->io))
427 return 0;
428 p -= sizeof(*trace->io);
429 while (p >= trace->start) {
430 test = (struct blk_io_trace *)p;
bfb0e441 431 if (CHECK_MAGIC(test) && is_io_event(test)) {
9e066e23
CM
432 u64 offset = p - trace->start;
433 if (offset + sizeof(*test) + test->pdu_len == trace->len) {
434 return test->time;
435 }
436 }
437 p--;
438 search_len++;
439 if (search_len > 8192) {
440 break;
441 }
442 }
443
444 /* searching backwards didn't work out, we'll have to scan the file */
445 first_record(trace);
446 while (1) {
bfb0e441 447 if (is_io_event(trace->io))
9e066e23
CM
448 found = trace->io->time;
449 if (next_record(trace))
450 break;
451 }
452 first_record(trace);
453 return found;
454}
455
bfb0e441
CM
456int parse_fio_bank_message(struct trace *trace, u64 *bank_ret, u64 *offset_ret,
457 u64 *num_banks_ret)
458{
459 char *s;
460 char *next;
461 char *message;
462 struct blk_io_trace *test = trace->io;
463 int len = test->pdu_len;
464 u64 bank;
465 u64 offset;
466 u64 num_banks;
467
468 if (!(test->action & BLK_TC_ACT(BLK_TC_NOTIFY)))
469 return -1;
470 if (test->action != BLK_TN_MESSAGE)
471 return -1;
472
473 /* the message is fio rw bank offset num_banks */
474 if (len < 3)
475 return -1;
476 message = (char *)(test + 1);
477 if (strncmp(message, "fio r ", 6) != 0)
478 return -1;
479
480 message = strndup(message, len);
481 s = strchr(message, ' ');
482 if (!s)
483 goto out;
484 s++;
485 s = strchr(s, ' ');
486 if (!s)
487 goto out;
488
489 bank = strtoll(s, &next, 10);
490 if (s == next)
491 goto out;
492 s = next;
493
494 offset = strtoll(s, &next, 10);
495 if (s == next)
496 goto out;
497 s = next;
498
499 num_banks = strtoll(s, &next, 10);
500 if (s == next)
501 goto out;
502
503 *bank_ret = bank;
504 *offset_ret = offset;
505 *num_banks_ret = num_banks;
506
507 return 0;
508out:
509 free(message);
510 return -1;
511}
512
9b9fa04b
JK
513void find_extreme_offsets(struct trace *trace, u64 *min_ret, u64 *max_ret, u64 *max_bank_ret,
514 u64 *max_offset_ret)
9e066e23
CM
515{
516 u64 found = 0;
9b9fa04b 517 u64 max = 0, min = ~(u64)0;
bfb0e441
CM
518 u64 max_bank = 0;
519 u64 max_bank_offset = 0;
520 u64 num_banks = 0;
9e066e23
CM
521 first_record(trace);
522 while (1) {
523 if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
524 found = trace->io->sector << 9;
9b9fa04b
JK
525 if (found < min)
526 min = found;
9e066e23 527
9b9fa04b
JK
528 found += trace->io->bytes;
529 if (max < found)
9e066e23 530 max = found;
bfb0e441
CM
531 } else {
532 u64 bank;
533 u64 offset;
534 if (!parse_fio_bank_message(trace, &bank,
535 &offset, &num_banks)) {
536 if (bank > max_bank)
537 max_bank = bank;
538 if (offset > max_bank_offset)
539 max_bank_offset = offset;
540 }
9e066e23
CM
541 }
542 if (next_record(trace))
543 break;
544 }
545 first_record(trace);
9b9fa04b 546 *min_ret = min;
bfb0e441
CM
547 *max_ret = max;
548 *max_bank_ret = max_bank;
549 *max_offset_ret = max_bank_offset;
9e066e23
CM
550}
551
854a1f24
CM
552static void check_io_types(struct trace *trace)
553{
554 struct blk_io_trace *io = trace->io;
555 int action = io->action & BLK_TA_MASK;
556
557 if (!(io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
558 switch (action) {
559 case __BLK_TA_COMPLETE:
560 trace->found_completion = 1;
561 break;
562 case __BLK_TA_ISSUE:
563 trace->found_issue = 1;
564 break;
565 case __BLK_TA_QUEUE:
566 trace->found_queue = 1;
567 break;
568 };
569 }
570}
571
572
9b9fa04b 573int filter_outliers(struct trace *trace, u64 min_offset, u64 max_offset,
9e066e23
CM
574 u64 *yzoom_min, u64 *yzoom_max)
575{
576 int hits[11];
577 u64 max_per_bucket[11];
9b9fa04b
JK
578 u64 min_per_bucket[11];
579 u64 bytes_per_bucket = (max_offset - min_offset + 1) / 10;
9e066e23
CM
580 int slot;
581 int fat_count = 0;
582
583 memset(hits, 0, sizeof(int) * 11);
584 memset(max_per_bucket, 0, sizeof(u64) * 11);
9b9fa04b 585 memset(min_per_bucket, 0xff, sizeof(u64) * 11);
9e066e23
CM
586 first_record(trace);
587 while (1) {
854a1f24 588 check_io_types(trace);
41fdf407
JK
589 if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) &&
590 (trace->io->action & BLK_TA_MASK) == __BLK_TA_QUEUE) {
9b9fa04b
JK
591 u64 off = (trace->io->sector << 9) - min_offset;
592
593 slot = (int)(off / bytes_per_bucket);
594 hits[slot]++;
595 if (off < min_per_bucket[slot])
596 min_per_bucket[slot] = off;
597
854a1f24 598 off += trace->io->bytes;
9b9fa04b 599 slot = (int)(off / bytes_per_bucket);
9e066e23 600 hits[slot]++;
9b9fa04b
JK
601 if (off > max_per_bucket[slot])
602 max_per_bucket[slot] = off;
9e066e23
CM
603 }
604 if (next_record(trace))
605 break;
606 }
607 first_record(trace);
608 for (slot = 0; slot < 11; slot++) {
609 if (hits[slot] > fat_count) {
610 fat_count = hits[slot];
611 }
612 }
613
614 *yzoom_max = max_offset;
615 for (slot = 10; slot >= 0; slot--) {
616 double d = hits[slot];
617
618 if (d >= (double)fat_count * .05) {
9b9fa04b 619 *yzoom_max = max_per_bucket[slot] + min_offset;
9e066e23
CM
620 break;
621 }
622 }
623
9b9fa04b 624 *yzoom_min = min_offset;
9e066e23
CM
625 for (slot = 0; slot < 10; slot++) {
626 double d = hits[slot];
627
628 if (d >= (double)fat_count * .05) {
9b9fa04b 629 *yzoom_min = min_per_bucket[slot] + min_offset;
9e066e23
CM
630 break;
631 }
632 }
633 return 0;
634}
635
636static char *find_trace_file(char *filename)
637{
638 int ret;
639 struct stat st;
640 char line[1024];
641 char *dot;
642 char *try;
643
644 ret = stat(filename, &st);
645 if (ret == 0)
646 return strdup(filename);
647
648 snprintf(line, 1024, "%s.%s", filename, "dump");
e199d546 649 ret = stat(line, &st);
9e066e23
CM
650 if (ret == 0)
651 return strdup(line);
652
653 try = strdup(filename);
654 dot = strrchr(try, '.');
655 if (!dot || strcmp(".dump", dot) != 0) {
e95ba659 656 if (dot && dot != try)
9e066e23
CM
657 *dot = '\0';
658 snprintf(line, 1024, "%s%s", try, ".blktrace.0");
659 ret = stat(line, &st);
660 if (ret == 0) {
661 blktrace_to_dump(try);
662 snprintf(line, 1024, "%s.%s", try, "dump");
663 ret = stat(line, &st);
664 if (ret == 0) {
665 free(try);
666 return strdup(line);
667 }
668 }
669 }
670 free(try);
671 return NULL;
672}
673struct trace *open_trace(char *filename)
674{
675 int fd;
676 char *p;
677 struct stat st;
678 int ret;
679 struct trace *trace;
680 char *found_filename;
681
682 trace = calloc(1, sizeof(*trace));
683 if (!trace) {
684 fprintf(stderr, "unable to allocate memory for trace\n");
685 return NULL;
686 }
687
688 found_filename = find_trace_file(filename);
689 if (!found_filename) {
690 fprintf(stderr, "Unable to find trace file %s\n", filename);
691 goto fail;
692 }
9e066e23
CM
693 filename = found_filename;
694
695 fd = open(filename, O_RDONLY);
696 if (fd < 0) {
697 fprintf(stderr, "Unable to open trace file %s err %s\n", filename, strerror(errno));
698 goto fail;
699 }
700 ret = fstat(fd, &st);
701 if (ret < 0) {
702 fprintf(stderr, "stat failed on %s err %s\n", filename, strerror(errno));
703 goto fail_fd;
704 }
705 p = mmap(NULL, st.st_size, PROT_READ, MAP_PRIVATE, fd, 0);
706 if (p == MAP_FAILED) {
707 fprintf(stderr, "Unable to mmap trace file %s, err %s\n", filename, strerror(errno));
708 goto fail_fd;
709 }
710 trace->fd = fd;
711 trace->len = st.st_size;
712 trace->start = p;
713 trace->cur = p;
714 trace->io = (struct blk_io_trace *)p;
715 return trace;
716
717fail_fd:
718 close(fd);
719fail:
720 free(trace);
721 return NULL;
722}
723static inline int tput_event(struct trace *trace)
724{
725 if (trace->found_completion)
726 return __BLK_TA_COMPLETE;
727 if (trace->found_issue)
728 return __BLK_TA_ISSUE;
729 if (trace->found_queue)
730 return __BLK_TA_QUEUE;
731
732 return __BLK_TA_COMPLETE;
733}
734
f2e40ddd
JK
735int action_char_to_num(char action)
736{
737 switch (action) {
738 case 'Q':
739 return __BLK_TA_QUEUE;
740 case 'D':
741 return __BLK_TA_ISSUE;
742 case 'C':
743 return __BLK_TA_COMPLETE;
744 }
745 return -1;
746}
747
9e066e23
CM
748static inline int io_event(struct trace *trace)
749{
f2e40ddd
JK
750 if (plot_io_action)
751 return plot_io_action;
9e066e23
CM
752 if (trace->found_queue)
753 return __BLK_TA_QUEUE;
754 if (trace->found_issue)
755 return __BLK_TA_ISSUE;
756 if (trace->found_completion)
757 return __BLK_TA_COMPLETE;
758
759 return __BLK_TA_COMPLETE;
760}
761
762void add_tput(struct trace *trace, struct graph_line_data *gld)
763{
764 struct blk_io_trace *io = trace->io;
1582ecc9 765 int action = io->action & BLK_TA_MASK;
9e066e23
CM
766 int seconds;
767
768 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
769 return;
770
771 if (action != tput_event(trace))
772 return;
773
774 seconds = SECONDS(io->time);
35686f9b
JK
775 if (seconds > gld->max_seconds)
776 return;
9e066e23
CM
777
778 gld->data[seconds].sum += io->bytes;
779 gld->data[seconds].count = 1;
780 if (gld->data[seconds].sum > gld->max)
781 gld->max = gld->data[seconds].sum;
782}
783
0a43b43f
JK
784#define GDD_PTR_ALLOC_STEP 16
785
786static struct pid_map *get_pid_map(struct trace_file *tf, u32 pid)
787{
788 struct pid_map *pm;
789
790 if (!io_per_process) {
791 if (!tf->io_plots)
792 tf->io_plots = 1;
793 return NULL;
794 }
795
796 pm = process_hash_insert(pid, NULL);
797 /* New entry? */
798 if (!pm->index) {
799 if (tf->io_plots == tf->io_plots_allocated) {
800 tf->io_plots_allocated += GDD_PTR_ALLOC_STEP;
801 tf->gdd_reads = realloc(tf->gdd_reads, tf->io_plots_allocated * sizeof(struct graph_dot_data *));
802 if (!tf->gdd_reads)
803 abort();
804 tf->gdd_writes = realloc(tf->gdd_writes, tf->io_plots_allocated * sizeof(struct graph_dot_data *));
805 if (!tf->gdd_writes)
806 abort();
807 memset(tf->gdd_reads + tf->io_plots_allocated - GDD_PTR_ALLOC_STEP,
808 0, GDD_PTR_ALLOC_STEP * sizeof(struct graph_dot_data *));
809 memset(tf->gdd_writes + tf->io_plots_allocated - GDD_PTR_ALLOC_STEP,
810 0, GDD_PTR_ALLOC_STEP * sizeof(struct graph_dot_data *));
811 }
812 pm->index = tf->io_plots++;
813
814 return pm;
815 }
816 return pm;
817}
818
819void add_io(struct trace *trace, struct trace_file *tf)
9e066e23
CM
820{
821 struct blk_io_trace *io = trace->io;
1582ecc9 822 int action = io->action & BLK_TA_MASK;
9e066e23 823 u64 offset;
0a43b43f
JK
824 int index;
825 char *label;
826 struct pid_map *pm;
9e066e23
CM
827
828 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
829 return;
830
831 if (action != io_event(trace))
832 return;
833
834 offset = io->sector << 9;
835
0a43b43f
JK
836 pm = get_pid_map(tf, io->pid);
837 if (!pm) {
838 index = 0;
839 label = "";
840 } else {
841 index = pm->index;
842 label = pm->name;
843 }
844 if (BLK_DATADIR(io->action) & BLK_TC_READ) {
845 if (!tf->gdd_reads[index])
846 tf->gdd_reads[index] = alloc_dot_data(tf->min_seconds, tf->max_seconds, tf->min_offset, tf->max_offset, tf->stop_seconds, pick_color(), strdup(label));
847 set_gdd_bit(tf->gdd_reads[index], offset, io->bytes, io->time);
848 } else if (BLK_DATADIR(io->action) & BLK_TC_WRITE) {
849 if (!tf->gdd_writes[index])
850 tf->gdd_writes[index] = alloc_dot_data(tf->min_seconds, tf->max_seconds, tf->min_offset, tf->max_offset, tf->stop_seconds, pick_color(), strdup(label));
851 set_gdd_bit(tf->gdd_writes[index], offset, io->bytes, io->time);
852 }
9e066e23
CM
853}
854
855void add_pending_io(struct trace *trace, struct graph_line_data *gld)
856{
9e066e23
CM
857 int seconds;
858 struct blk_io_trace *io = trace->io;
1582ecc9 859 int action = io->action & BLK_TA_MASK;
9e066e23 860 double avg;
854a1f24 861 struct pending_io *pio;
9e066e23
CM
862
863 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
864 return;
865
0a43b43f 866 if (action == __BLK_TA_QUEUE) {
854a1f24
CM
867 if (trace->found_issue || trace->found_completion)
868 hash_queued_io(trace->io);
0a43b43f
JK
869 return;
870 }
9e066e23
CM
871 if (action != __BLK_TA_ISSUE)
872 return;
873
874 seconds = SECONDS(io->time);
35686f9b
JK
875 if (seconds > gld->max_seconds)
876 return;
9e066e23 877
854a1f24
CM
878 pio = hash_dispatched_io(trace->io);
879 if (!pio)
9e066e23
CM
880 return;
881
854a1f24
CM
882 if (!trace->found_completion) {
883 list_del(&pio->hash_list);
884 free(pio);
885 }
886
9e066e23
CM
887 ios_in_flight++;
888
889 gld->data[seconds].sum += ios_in_flight;
890 gld->data[seconds].count++;
891
892 avg = (double)gld->data[seconds].sum / gld->data[seconds].count;
893 if (gld->max < (u64)avg) {
894 gld->max = avg;
895 }
896}
897
898void add_completed_io(struct trace *trace,
899 struct graph_line_data *latency_gld)
900{
901 struct blk_io_trace *io = trace->io;
902 int seconds;
1582ecc9 903 int action = io->action & BLK_TA_MASK;
9e066e23
CM
904 struct pending_io *pio;
905 double avg;
906 u64 latency;
907
908 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
909 return;
910
911 if (action != __BLK_TA_COMPLETE)
912 return;
913
914 seconds = SECONDS(io->time);
915
916 pio = hash_completed_io(trace->io);
917 if (!pio)
918 return;
919
920 if (ios_in_flight > 0)
921 ios_in_flight--;
922 if (io->time >= pio->dispatch_time) {
923 latency = io->time - pio->dispatch_time;
924 latency_gld->data[seconds].sum += latency;
925 latency_gld->data[seconds].count++;
926 }
927
928 list_del(&pio->hash_list);
929 free(pio);
930
931 avg = (double)latency_gld->data[seconds].sum /
932 latency_gld->data[seconds].count;
933 if (latency_gld->max < (u64)avg) {
934 latency_gld->max = avg;
935 }
936}
937
938void add_iop(struct trace *trace, struct graph_line_data *gld)
939{
940 struct blk_io_trace *io = trace->io;
1582ecc9 941 int action = io->action & BLK_TA_MASK;
9e066e23
CM
942 int seconds;
943
944 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
945 return;
946
947 /* iops and tput use the same events */
948 if (action != tput_event(trace))
949 return;
950
951 seconds = SECONDS(io->time);
35686f9b
JK
952 if (seconds > gld->max_seconds)
953 return;
9e066e23
CM
954
955 gld->data[seconds].sum += 1;
956 gld->data[seconds].count = 1;
957 if (gld->data[seconds].sum > gld->max)
958 gld->max = gld->data[seconds].sum;
959}
960
961void check_record(struct trace *trace)
962{
9e066e23
CM
963 handle_notify(trace);
964}