2 * Copyright (C) 2012 Fusion-io
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.
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.
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., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
17 * Parts of this file were imported from Jens Axboe's blktrace sources (also GPL)
19 #include <sys/types.h>
28 #include <asm/types.h>
39 #include "../blktrace_api.h"
41 #define IO_HASH_TABLE_BITS 11
42 #define IO_HASH_TABLE_SIZE (1 << IO_HASH_TABLE_BITS)
43 static struct list_head io_hash_table[IO_HASH_TABLE_SIZE];
45 #define PROCESS_HASH_TABLE_BITS 7
46 #define PROCESS_HASH_TABLE_SIZE (1 << PROCESS_HASH_TABLE_BITS)
47 static struct list_head process_hash_table[PROCESS_HASH_TABLE_SIZE];
49 extern int plot_io_action;
50 extern int io_per_process;
52 #define BLK_DATADIR(a) (((a) >> BLK_TC_SHIFT) & (BLK_TC_READ | BLK_TC_WRITE))
53 #define BLK_TA_MASK (((1 << BLK_TC_SHIFT) - 1) & ~__BLK_TA_CGROUP)
56 /* sector offset of this IO */
59 /* dev_t for this IO */
62 /* time this IO was dispatched */
64 /* time this IO was finished */
66 struct list_head hash_list;
67 /* process which queued this IO */
72 struct list_head hash_list;
78 u64 get_record_time(struct trace *trace)
80 return trace->io->time;
83 void init_io_hash_table(void)
86 struct list_head *head;
88 for (i = 0; i < IO_HASH_TABLE_SIZE; i++) {
89 head = io_hash_table + i;
94 /* taken from the kernel hash.h */
95 static inline u64 hash_sector(u64 val)
99 /* Sigh, gcc can't optimise this alone like it does for 32 bits. */
114 /* High bits are more random, so use them. */
115 return hash >> (64 - IO_HASH_TABLE_BITS);
118 static int io_hash_table_insert(struct pending_io *ins_pio)
120 u64 sector = ins_pio->sector;
121 u32 dev = ins_pio->device;
122 int slot = hash_sector(sector);
123 struct list_head *head;
124 struct pending_io *pio;
126 head = io_hash_table + slot;
127 list_for_each_entry(pio, head, hash_list) {
128 if (pio->sector == sector && pio->device == dev)
131 list_add_tail(&ins_pio->hash_list, head);
135 static struct pending_io *io_hash_table_search(u64 sector, u32 dev)
137 int slot = hash_sector(sector);
138 struct list_head *head;
139 struct pending_io *pio;
141 head = io_hash_table + slot;
142 list_for_each_entry(pio, head, hash_list) {
143 if (pio->sector == sector && pio->device == dev)
149 static struct pending_io *hash_queued_io(struct blk_io_trace *io)
151 struct pending_io *pio;
154 pio = calloc(1, sizeof(*pio));
155 pio->sector = io->sector;
156 pio->device = io->device;
159 ret = io_hash_table_insert(pio);
161 /* crud, the IO is there already */
168 static struct pending_io *hash_dispatched_io(struct blk_io_trace *io)
170 struct pending_io *pio;
172 pio = io_hash_table_search(io->sector, io->device);
174 pio = hash_queued_io(io);
178 pio->dispatch_time = io->time;
182 static struct pending_io *hash_completed_io(struct blk_io_trace *io)
184 struct pending_io *pio;
186 pio = io_hash_table_search(io->sector, io->device);
193 void init_process_hash_table(void)
196 struct list_head *head;
198 for (i = 0; i < PROCESS_HASH_TABLE_SIZE; i++) {
199 head = process_hash_table + i;
200 INIT_LIST_HEAD(head);
204 static u32 hash_pid(u32 pid)
212 return (hash & (PROCESS_HASH_TABLE_SIZE - 1));
215 static struct pid_map *process_hash_search(u32 pid)
217 int slot = hash_pid(pid);
218 struct list_head *head;
221 head = process_hash_table + slot;
222 list_for_each_entry(pm, head, hash_list) {
229 static struct pid_map *process_hash_insert(u32 pid, char *name)
231 int slot = hash_pid(pid);
236 pm = process_hash_search(pid);
238 /* Entry exists and name shouldn't be changed? */
239 if (!name || !strcmp(name, pm->name))
241 list_del(&pm->hash_list);
242 old_index = pm->index;
246 sprintf(buf, "[%u]", pid);
249 pm = malloc(sizeof(struct pid_map) + strlen(name) + 1);
251 pm->index = old_index;
252 strcpy(pm->name, name);
253 list_add_tail(&pm->hash_list, process_hash_table + slot);
258 static void handle_notify(struct trace *trace)
260 struct blk_io_trace *io = trace->io;
261 void *payload = (char *)io + sizeof(*io);
262 int pdu_len = io->pdu_len;
265 if (io->action & __BLK_TN_CGROUP) {
266 payload += sizeof(struct blk_io_cgroup_payload);
267 pdu_len -= sizeof(struct blk_io_cgroup_payload);
269 if ((io->action & ~__BLK_TN_CGROUP) == BLK_TN_PROCESS) {
271 process_hash_insert(io->pid, payload);
275 if ((io->action & ~__BLK_TN_CGROUP) != BLK_TN_TIMESTAMP)
278 if (pdu_len != sizeof(two32))
281 memcpy(two32, payload, sizeof(two32));
282 trace->start_timestamp = io->time;
283 trace->abs_start_time.tv_sec = two32[0];
284 trace->abs_start_time.tv_nsec = two32[1];
285 if (trace->abs_start_time.tv_nsec < 0) {
286 trace->abs_start_time.tv_sec--;
287 trace->abs_start_time.tv_nsec += 1000000000;
291 int next_record(struct trace *trace)
293 int skip = trace->io->pdu_len;
296 trace->cur += sizeof(*trace->io) + skip;
297 offset = trace->cur - trace->start;
298 if (offset >= trace->len)
301 trace->io = (struct blk_io_trace *)trace->cur;
305 void first_record(struct trace *trace)
307 trace->cur = trace->start;
308 trace->io = (struct blk_io_trace *)trace->cur;
311 static int is_io_event(struct blk_io_trace *test)
314 if (!(test->action & BLK_TC_ACT(BLK_TC_NOTIFY)))
316 if ((test->action & ~__BLK_TN_CGROUP) == BLK_TN_MESSAGE) {
317 int len = test->pdu_len;
319 message = (char *)(test + 1);
320 if (test->action & __BLK_TN_CGROUP) {
321 len -= sizeof(struct blk_io_cgroup_payload);
322 message += sizeof(struct blk_io_cgroup_payload);
326 if (strncmp(message, "fio ", 4) == 0) {
333 u64 find_last_time(struct trace *trace)
335 char *p = trace->start + trace->len;
336 struct blk_io_trace *test;
340 if (trace->len < sizeof(*trace->io))
342 p -= sizeof(*trace->io);
343 while (p >= trace->start) {
344 test = (struct blk_io_trace *)p;
345 if (CHECK_MAGIC(test) && is_io_event(test)) {
346 u64 offset = p - trace->start;
347 if (offset + sizeof(*test) + test->pdu_len == trace->len) {
353 if (search_len > 8192) {
358 /* searching backwards didn't work out, we'll have to scan the file */
361 if (is_io_event(trace->io))
362 found = trace->io->time;
363 if (next_record(trace))
370 static int parse_fio_bank_message(struct trace *trace, u64 *bank_ret, u64 *offset_ret,
376 struct blk_io_trace *test = trace->io;
377 int len = test->pdu_len;
382 if (!(test->action & BLK_TC_ACT(BLK_TC_NOTIFY)))
384 if ((test->action & ~__BLK_TN_CGROUP) != BLK_TN_MESSAGE)
387 message = (char *)(test + 1);
388 if (test->action & __BLK_TN_CGROUP) {
389 len -= sizeof(struct blk_io_cgroup_payload);
390 message += sizeof(struct blk_io_cgroup_payload);
392 /* the message is fio rw bank offset num_banks */
395 if (strncmp(message, "fio r ", 6) != 0)
398 message = strndup(message, len);
399 s = strchr(message, ' ');
407 bank = strtoll(s, &next, 10);
412 offset = strtoll(s, &next, 10);
417 num_banks = strtoll(s, &next, 10);
422 *offset_ret = offset;
423 *num_banks_ret = num_banks;
431 static struct dev_info *lookup_dev(struct trace *trace, struct blk_io_trace *io)
433 u32 dev = io->device;
435 struct dev_info *di = NULL;
437 for (i = 0; i < trace->num_devices; i++) {
438 if (trace->devices[i].device == dev) {
439 di = trace->devices + i;
443 i = trace->num_devices++;
444 if (i >= MAX_DEVICES_PER_TRACE) {
445 fprintf(stderr, "Trace contains too many devices (%d)\n", i);
448 di = trace->devices + i;
454 static void map_devices(struct trace *trace)
463 if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
464 di = lookup_dev(trace, trace->io);
465 found = trace->io->sector << 9;
469 found += trace->io->bytes;
473 if (next_record(trace))
477 for (i = 0; i < trace->num_devices; i++) {
478 di = trace->devices + i;
480 map_start += di->max - di->min;
484 static u64 map_io(struct trace *trace, struct blk_io_trace *io)
486 struct dev_info *di = lookup_dev(trace, io);
487 u64 val = trace->io->sector << 9;
488 return di->map + val - di->min;
491 void find_extreme_offsets(struct trace *trace, u64 *min_ret, u64 *max_ret, u64 *max_bank_ret,
495 u64 max = 0, min = ~(u64)0;
497 u64 max_bank_offset = 0;
504 if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
505 found = map_io(trace, trace->io);
509 found += trace->io->bytes;
515 if (!parse_fio_bank_message(trace, &bank,
516 &offset, &num_banks)) {
519 if (offset > max_bank_offset)
520 max_bank_offset = offset;
523 if (next_record(trace))
529 *max_bank_ret = max_bank;
530 *max_offset_ret = max_bank_offset;
533 static void check_io_types(struct trace *trace)
535 struct blk_io_trace *io = trace->io;
536 int action = io->action & BLK_TA_MASK;
538 if (!(io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) {
540 case __BLK_TA_COMPLETE:
541 trace->found_completion = 1;
544 trace->found_issue = 1;
547 trace->found_queue = 1;
554 int filter_outliers(struct trace *trace, u64 min_offset, u64 max_offset,
555 u64 *yzoom_min, u64 *yzoom_max)
558 u64 max_per_bucket[11];
559 u64 min_per_bucket[11];
560 u64 bytes_per_bucket = (max_offset - min_offset + 1) / 10;
564 memset(hits, 0, sizeof(int) * 11);
565 memset(max_per_bucket, 0, sizeof(u64) * 11);
566 memset(min_per_bucket, 0xff, sizeof(u64) * 11);
569 check_io_types(trace);
570 if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) &&
571 (trace->io->action & BLK_TA_MASK) == __BLK_TA_QUEUE) {
572 u64 off = map_io(trace, trace->io) - min_offset;
574 slot = (int)(off / bytes_per_bucket);
576 if (off < min_per_bucket[slot])
577 min_per_bucket[slot] = off;
579 off += trace->io->bytes;
580 slot = (int)(off / bytes_per_bucket);
582 if (off > max_per_bucket[slot])
583 max_per_bucket[slot] = off;
585 if (next_record(trace))
589 for (slot = 0; slot < 11; slot++) {
590 if (hits[slot] > fat_count) {
591 fat_count = hits[slot];
595 *yzoom_max = max_offset;
596 for (slot = 10; slot >= 0; slot--) {
597 double d = hits[slot];
599 if (d >= (double)fat_count * .05) {
600 *yzoom_max = max_per_bucket[slot] + min_offset;
605 *yzoom_min = min_offset;
606 for (slot = 0; slot < 10; slot++) {
607 double d = hits[slot];
609 if (d >= (double)fat_count * .05) {
610 *yzoom_min = min_per_bucket[slot] + min_offset;
617 static char footer[] = ".blktrace.0";
618 static int footer_len = sizeof(footer) - 1;
620 static int match_trace(char *name, int *len)
625 match_len = strlen(name);
626 if (match_len <= footer_len)
629 footer_start = match_len - footer_len;
630 if (strcmp(name + footer_start, footer) != 0)
639 struct tracelist *next;
643 static struct tracelist *traces_list(char *dir_name, int *len)
646 struct tracelist *traces = NULL;
647 int dlen = strlen(dir_name);
648 DIR *dir = opendir(dir_name);
654 struct tracelist *tl;
655 struct dirent *d = readdir(dir);
659 if (!match_trace(d->d_name, &n))
662 n += dlen + 1; /* dir + '/' + file */
663 /* Allocate space for tracelist + filename */
664 tl = calloc(1, sizeof(struct tracelist) + (sizeof(char) * (n + 1)));
670 tl->name = (char *)(tl + 1);
671 snprintf(tl->name, n, "%s/%s", dir_name, d->d_name);
684 static void traces_free(struct tracelist *traces)
687 struct tracelist *tl = traces;
688 traces = traces->next;
693 static int dump_traces(struct tracelist *traces, int count, char *dumpfile)
695 struct tracelist *tl;
701 argc = count * 2; /* {"-i", trace } */
702 argc += 4; /* See below */
703 argv = calloc(argc + 1, sizeof(char *));
708 argv[i++] = "blkparse";
711 argv[i++] = dumpfile;
712 for (tl = traces; tl != NULL; tl = tl->next) {
714 argv[i++] = tl->name;
717 err = run_program(argc, argv, 1, NULL, NULL);
719 fprintf(stderr, "%s exited with %d, expected 0\n", argv[0], err);
724 static char *find_trace_file(char *filename)
731 int len = strlen(filename);
733 /* look for an exact match of whatever they pass in.
734 * If it is a file, assume it is the dump file.
735 * If a directory, remember that it existed so we
736 * can combine traces in that directory later
738 ret = stat(filename, &st);
740 if (S_ISREG(st.st_mode))
741 return strdup(filename);
743 if (S_ISDIR(st.st_mode))
749 /* Eat up trailing '/'s */
750 for (i = len - 1; filename[i] == '/'; i--)
755 * try tacking .dump onto the end and see if that already
758 ret = asprintf(&dumpfile, "%s.dump", filename);
760 perror("Error building dump file name");
763 ret = stat(dumpfile, &st);
768 * try to generate the .dump from all the traces in
773 struct tracelist *traces = traces_list(filename, &count);
775 ret = dump_traces(traces, count, dumpfile);
784 * try to generate the .dump from all the blktrace
785 * files for a named trace
787 dot = strrchr(filename, '.');
788 if (!dot || strcmp(".dump", dot) != 0) {
789 struct tracelist trace = {0 ,NULL};
790 if (dot && dot != filename)
791 len = dot - filename;
793 ret = asprintf(&trace.name, "%*s.blktrace.0", len, filename);
796 ret = asprintf(&dumpfile, "%*s.dump", len, filename);
802 ret = dump_traces(&trace, 1, dumpfile);
812 struct trace *open_trace(char *filename)
819 char *found_filename;
821 trace = calloc(1, sizeof(*trace));
823 fprintf(stderr, "unable to allocate memory for trace\n");
827 found_filename = find_trace_file(filename);
828 if (!found_filename) {
829 fprintf(stderr, "Unable to find trace file %s\n", filename);
832 filename = found_filename;
834 fd = open(filename, O_RDONLY);
836 fprintf(stderr, "Unable to open trace file %s err %s\n", filename, strerror(errno));
839 ret = fstat(fd, &st);
841 fprintf(stderr, "stat failed on %s err %s\n", filename, strerror(errno));
844 p = mmap(NULL, st.st_size, PROT_READ, MAP_PRIVATE, fd, 0);
845 if (p == MAP_FAILED) {
846 fprintf(stderr, "Unable to mmap trace file %s, err %s\n", filename, strerror(errno));
850 trace->len = st.st_size;
853 trace->io = (struct blk_io_trace *)p;
862 static inline int tput_event(struct trace *trace)
864 if (trace->found_completion)
865 return __BLK_TA_COMPLETE;
866 if (trace->found_issue)
867 return __BLK_TA_ISSUE;
868 if (trace->found_queue)
869 return __BLK_TA_QUEUE;
871 return __BLK_TA_COMPLETE;
874 int action_char_to_num(char action)
878 return __BLK_TA_QUEUE;
880 return __BLK_TA_ISSUE;
882 return __BLK_TA_COMPLETE;
887 static inline int io_event(struct trace *trace)
890 return plot_io_action;
891 if (trace->found_queue)
892 return __BLK_TA_QUEUE;
893 if (trace->found_issue)
894 return __BLK_TA_ISSUE;
895 if (trace->found_completion)
896 return __BLK_TA_COMPLETE;
898 return __BLK_TA_COMPLETE;
901 void add_tput(struct trace *trace, struct graph_line_data *writes_gld,
902 struct graph_line_data *reads_gld)
904 struct blk_io_trace *io = trace->io;
905 struct graph_line_data *gld;
906 int action = io->action & BLK_TA_MASK;
909 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
912 if (action != tput_event(trace))
915 if (BLK_DATADIR(io->action) & BLK_TC_READ)
920 seconds = SECONDS(io->time);
921 gld->data[seconds].sum += io->bytes;
923 gld->data[seconds].count = 1;
924 if (gld->data[seconds].sum > gld->max)
925 gld->max = gld->data[seconds].sum;
928 #define GDD_PTR_ALLOC_STEP 16
930 static struct pid_map *get_pid_map(struct trace_file *tf, u32 pid)
934 if (!io_per_process) {
940 pm = process_hash_insert(pid, NULL);
943 if (tf->io_plots == tf->io_plots_allocated) {
944 tf->io_plots_allocated += GDD_PTR_ALLOC_STEP;
945 tf->gdd_reads = realloc(tf->gdd_reads, tf->io_plots_allocated * sizeof(struct graph_dot_data *));
948 tf->gdd_writes = realloc(tf->gdd_writes, tf->io_plots_allocated * sizeof(struct graph_dot_data *));
951 memset(tf->gdd_reads + tf->io_plots_allocated - GDD_PTR_ALLOC_STEP,
952 0, GDD_PTR_ALLOC_STEP * sizeof(struct graph_dot_data *));
953 memset(tf->gdd_writes + tf->io_plots_allocated - GDD_PTR_ALLOC_STEP,
954 0, GDD_PTR_ALLOC_STEP * sizeof(struct graph_dot_data *));
956 pm->index = tf->io_plots++;
963 void add_io(struct trace *trace, struct trace_file *tf)
965 struct blk_io_trace *io = trace->io;
966 int action = io->action & BLK_TA_MASK;
972 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
975 if (action != io_event(trace))
978 offset = map_io(trace, io);
980 pm = get_pid_map(tf, io->pid);
988 if (BLK_DATADIR(io->action) & BLK_TC_READ) {
989 if (!tf->gdd_reads[index])
990 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));
991 set_gdd_bit(tf->gdd_reads[index], offset, io->bytes, io->time);
992 } else if (BLK_DATADIR(io->action) & BLK_TC_WRITE) {
993 if (!tf->gdd_writes[index])
994 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));
995 set_gdd_bit(tf->gdd_writes[index], offset, io->bytes, io->time);
999 void add_pending_io(struct trace *trace, struct graph_line_data *gld)
1001 unsigned int seconds;
1002 struct blk_io_trace *io = trace->io;
1003 int action = io->action & BLK_TA_MASK;
1005 struct pending_io *pio;
1007 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
1010 if (action == __BLK_TA_QUEUE) {
1011 if (io->sector == 0)
1014 * If D (issue) events are available, use them for I/O
1015 * accounting. Nothing needs to be done for Q.
1017 if (trace->found_issue)
1020 * If there are no D or C events, then all that can be
1021 * done is to account the Q event (and make sure not to
1022 * add the I/O to the hash, because it will never be
1025 if (!trace->found_completion)
1028 * When there are no ISSUE events, count depth and
1029 * latency from queue events.
1031 pio = hash_queued_io(trace->io);
1033 pio->dispatch_time = io->time;
1038 if (action == __BLK_TA_REQUEUE) {
1039 if (trace->ios_in_flight > 0)
1040 trace->ios_in_flight--;
1043 if (action != __BLK_TA_ISSUE)
1046 pio = hash_dispatched_io(trace->io);
1050 if (!trace->found_completion) {
1051 list_del(&pio->hash_list);
1056 trace->ios_in_flight++;
1058 seconds = SECONDS(io->time);
1059 gld->data[seconds].sum += trace->ios_in_flight;
1060 gld->data[seconds].count++;
1062 avg = (double)gld->data[seconds].sum / gld->data[seconds].count;
1063 if (gld->max < (u64)avg) {
1068 void add_completed_io(struct trace *trace,
1069 struct graph_line_data *latency_gld)
1071 struct blk_io_trace *io = trace->io;
1073 int action = io->action & BLK_TA_MASK;
1074 struct pending_io *pio;
1078 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
1081 if (action != __BLK_TA_COMPLETE)
1084 seconds = SECONDS(io->time);
1086 pio = hash_completed_io(trace->io);
1090 if (trace->ios_in_flight > 0)
1091 trace->ios_in_flight--;
1092 if (io->time >= pio->dispatch_time) {
1093 latency = io->time - pio->dispatch_time;
1094 latency_gld->data[seconds].sum += latency;
1095 latency_gld->data[seconds].count++;
1098 list_del(&pio->hash_list);
1101 avg = (double)latency_gld->data[seconds].sum /
1102 latency_gld->data[seconds].count;
1103 if (latency_gld->max < (u64)avg) {
1104 latency_gld->max = avg;
1108 void add_iop(struct trace *trace, struct graph_line_data *gld)
1110 struct blk_io_trace *io = trace->io;
1111 int action = io->action & BLK_TA_MASK;
1114 if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY))
1117 /* iops and tput use the same events */
1118 if (action != tput_event(trace))
1121 seconds = SECONDS(io->time);
1122 gld->data[seconds].sum += 1;
1123 gld->data[seconds].count = 1;
1124 if (gld->data[seconds].sum > gld->max)
1125 gld->max = gld->data[seconds].sum;
1128 void check_record(struct trace *trace)
1130 handle_notify(trace);