2 * block queue tracing parse application
4 * Copyright (C) 2005 Jens Axboe <axboe@suse.de>
6 * This program is free software; you can redistribute it and/or modify
7 * it under the terms of the GNU General Public License as published by
8 * the Free Software Foundation; either version 2 of the License, or
9 * (at your option) any later version.
11 * This program is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14 * GNU General Public License for more details.
16 * You should have received a copy of the GNU General Public License
17 * along with this program; if not, write to the Free Software
18 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
21 #include <sys/types.h>
35 #define SECONDS(x) ((unsigned long long)(x) / 1000000000)
36 #define NANO_SECONDS(x) ((unsigned long long)(x) % 1000000000)
39 static unsigned long long genesis_time, last_reported_time;
51 unsigned long qreads, qwrites, creads, cwrites, mreads, mwrites;
52 unsigned long ireads, iwrites;
53 unsigned long long qread_kb, qwrite_kb, cread_kb, cwrite_kb;
54 unsigned long long iread_kb, iwrite_kb;
58 static struct option l_opts[] = {
79 static struct rb_root rb_root;
82 struct blk_io_trace *bit;
83 struct rb_node rb_node;
87 static struct per_cpu_info *per_cpu_info;
89 static unsigned long long events;
91 static char *dev, *output_name;
93 #define is_done() (*(volatile int *)(&done))
94 static volatile int done;
96 static void resize_cpu_info(int cpuid)
98 int new_space, new_max = cpuid + 1;
101 per_cpu_info = realloc(per_cpu_info, new_max * sizeof(*per_cpu_info));
103 fprintf(stderr, "Cannot allocate CPU info -- %d x %d bytes\n",
104 new_max, (int) sizeof(*per_cpu_info));
108 new_start = (char *)per_cpu_info + (max_cpus * sizeof(*per_cpu_info));
109 new_space = (new_max - max_cpus) * sizeof(*per_cpu_info);
110 memset(new_start, 0, new_space);
114 static struct per_cpu_info *get_cpu_info(int cpu)
116 struct per_cpu_info *pci;
119 resize_cpu_info(cpu);
122 * ->cpu might already be set, but just set it unconditionally
124 pci = &per_cpu_info[cpu];
130 static inline void check_time(struct blk_io_trace *bit)
132 unsigned long long this = bit->time;
133 unsigned long long last = last_reported_time;
135 backwards = (this < last) ? 'B' : ' ';
136 last_reported_time = this;
139 static inline void account_m(struct per_cpu_info *pci, int rw,
144 pci->qwrite_kb += bytes >> 10;
147 pci->qread_kb += bytes >> 10;
151 static inline void account_q(struct per_cpu_info *pci, int rw,
156 pci->qwrite_kb += bytes >> 10;
159 pci->qread_kb += bytes >> 10;
163 static inline void account_c(struct per_cpu_info *pci, int rw,
168 pci->cwrite_kb += bytes >> 10;
171 pci->cread_kb += bytes >> 10;
175 static inline void account_i(struct per_cpu_info *pci, int rw,
180 pci->iwrite_kb += bytes >> 10;
183 pci->iread_kb += bytes >> 10;
187 static void output(struct per_cpu_info *pci, char *s)
192 fprintf(pci->ofp, "%s", s);
195 static char hstring[256];
196 static char tstring[256];
198 static inline char *setup_header(struct per_cpu_info *pci,
199 struct blk_io_trace *t, char act)
201 int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
202 int b = t->action & BLK_TC_ACT(BLK_TC_BARRIER);
203 int s = t->action & BLK_TC_ACT(BLK_TC_SYNC);
218 sprintf(hstring, "%c %3d %15ld %5Lu.%09Lu %5u %c %3s", backwards,
220 (unsigned long)t->sequence, SECONDS(t->time),
221 NANO_SECONDS(t->time), t->pid, act, rwbs);
226 static void log_complete(struct per_cpu_info *pci, struct blk_io_trace *t,
229 sprintf(tstring,"%s %Lu + %u [%d]\n", setup_header(pci, t, act),
230 (unsigned long long)t->sector, t->bytes >> 9, t->error);
231 output(pci, tstring);
234 static void log_queue(struct per_cpu_info *pci, struct blk_io_trace *t,
237 sprintf(tstring,"%s %Lu + %u [%s]\n", setup_header(pci, t, act),
238 (unsigned long long)t->sector, t->bytes >> 9, t->comm);
239 output(pci, tstring);
242 static void log_issue(struct per_cpu_info *pci, struct blk_io_trace *t,
245 sprintf(tstring,"%s %Lu + %u [%s]\n", setup_header(pci, t, act),
246 (unsigned long long)t->sector, t->bytes >> 9, t->comm);
247 output(pci, tstring);
250 static void log_merge(struct per_cpu_info *pci, struct blk_io_trace *t,
253 sprintf(tstring,"%s %Lu + %u [%s]\n", setup_header(pci, t, act),
254 (unsigned long long)t->sector, t->bytes >> 9, t->comm);
255 output(pci, tstring);
258 static void log_generic(struct per_cpu_info *pci, struct blk_io_trace *t,
261 sprintf(tstring,"%s %Lu + %u [%s]\n", setup_header(pci, t, act),
262 (unsigned long long)t->sector, t->bytes >> 9, t->comm);
263 output(pci, tstring);
266 static int log_pc(struct per_cpu_info *pci, struct blk_io_trace *t, char act)
271 sprintf(tstring,"%s ", setup_header(pci, t, act));
272 output(pci, tstring);
274 buf = (unsigned char *) t + sizeof(*t);
275 for (i = 0; i < t->pdu_len; i++) {
276 sprintf(tstring,"%02x ", buf[i]);
277 output(pci, tstring);
281 sprintf(tstring,"[%d]\n", t->error);
282 output(pci, tstring);
284 sprintf(tstring,"[%s]\n", t->comm);
285 output(pci, tstring);
290 static int dump_trace_pc(struct blk_io_trace *t, struct per_cpu_info *pci)
294 switch (t->action & 0xffff) {
296 log_generic(pci, t, 'Q');
299 log_generic(pci, t, 'G');
301 case __BLK_TA_SLEEPRQ:
302 log_generic(pci, t, 'S');
304 case __BLK_TA_REQUEUE:
305 log_generic(pci, t, 'R');
308 ret = log_pc(pci, t, 'D');
310 case __BLK_TA_COMPLETE:
314 fprintf(stderr, "Bad pc action %x\n", t->action);
322 static void dump_trace_fs(struct blk_io_trace *t, struct per_cpu_info *pci)
324 int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
326 switch (t->action & 0xffff) {
328 account_q(pci, w, t->bytes);
329 log_queue(pci, t, 'Q');
331 case __BLK_TA_BACKMERGE:
332 account_m(pci, w, t->bytes);
333 log_merge(pci, t, 'M');
335 case __BLK_TA_FRONTMERGE:
336 account_m(pci, w, t->bytes);
337 log_merge(pci, t, 'F');
340 log_generic(pci, t, 'G');
342 case __BLK_TA_SLEEPRQ:
343 log_generic(pci, t, 'S');
345 case __BLK_TA_REQUEUE:
346 account_c(pci, w, -t->bytes);
347 log_queue(pci, t, 'R');
350 account_i(pci, w, t->bytes);
351 log_issue(pci, t, 'D');
353 case __BLK_TA_COMPLETE:
354 account_c(pci, w, t->bytes);
355 log_complete(pci, t, 'C');
358 fprintf(stderr, "Bad fs action %x\n", t->action);
363 static int dump_trace(struct blk_io_trace *t, struct per_cpu_info *pci)
367 if (output_name && !pci->ofp) {
368 snprintf(pci->ofname, sizeof(pci->ofname) - 1,
369 "%s_log.%d", output_name, pci->cpu);
371 pci->ofp = fopen(pci->ofname, "w");
372 if (pci->ofp == NULL) {
378 if (t->action & BLK_TC_ACT(BLK_TC_PC))
379 ret = dump_trace_pc(t, pci);
381 dump_trace_fs(t, pci);
387 static void dump_pci_stats(struct per_cpu_info *pci)
389 printf(" Reads Queued: %'8lu, %'8LuKiB\t", pci->qreads, pci->qread_kb);
390 printf(" Writes Queued: %'8lu, %'8LuKiB\n", pci->qwrites,pci->qwrite_kb);
392 printf(" Read Dispatches: %'8lu, %'8LuKiB\t", pci->ireads, pci->iread_kb);
393 printf(" Write Dispatches: %'8lu, %'8LuKiB\n", pci->iwrites,pci->iwrite_kb);
394 printf(" Reads Completed: %'8lu, %'8LuKiB\t", pci->creads, pci->cread_kb);
395 printf(" Writes Completed: %'8lu, %'8LuKiB\n", pci->cwrites,pci->cwrite_kb);
396 printf(" Read Merges: %'8lu%8c\t", pci->mreads, ' ');
398 printf(" Write Merges: %'8lu\n", pci->mwrites);
401 static void show_stats(void)
403 struct per_cpu_info foo, *pci;
404 int i, pci_events = 0;
406 memset(&foo, 0, sizeof(foo));
408 for (i = 0; i < max_cpus; i++) {
409 pci = &per_cpu_info[i];
414 foo.qreads += pci->qreads;
415 foo.qwrites += pci->qwrites;
416 foo.creads += pci->creads;
417 foo.cwrites += pci->cwrites;
418 foo.mreads += pci->mreads;
419 foo.mwrites += pci->mwrites;
420 foo.qread_kb += pci->qread_kb;
421 foo.qwrite_kb += pci->qwrite_kb;
422 foo.cread_kb += pci->cread_kb;
423 foo.cwrite_kb += pci->cwrite_kb;
425 printf("CPU%d:\n", i);
430 if (pci_events > 1) {
432 dump_pci_stats(&foo);
435 printf("Events: %'Lu\n", events);
438 static inline int trace_rb_insert(struct trace *t)
440 struct rb_node **p = &rb_root.rb_node;
441 struct rb_node *parent = NULL;
446 __t = rb_entry(parent, struct trace, rb_node);
448 if (t->bit->sequence < __t->bit->sequence)
450 else if (t->bit->sequence > __t->bit->sequence)
453 fprintf(stderr, "sequence alias!\n");
458 rb_link_node(&t->rb_node, parent, p);
459 rb_insert_color(&t->rb_node, &rb_root);
463 static int sort_entries(void *traces, unsigned long offset, int nr)
465 struct per_cpu_info *pci;
466 struct blk_io_trace *bit;
468 void *start = traces;
471 while (traces - start <= offset - sizeof(*bit)) {
477 t = malloc(sizeof(*t));
479 memset(&t->rb_node, 0, sizeof(t->rb_node));
483 if (verify_trace(bit))
486 pci = get_cpu_info(bit->cpu);
489 if (trace_rb_insert(t))
492 traces += sizeof(*bit) + bit->pdu_len;
500 static void free_entries_rb(void)
504 while ((n = rb_first(&rb_root)) != NULL) {
505 struct trace *t = rb_entry(n, struct trace, rb_node);
507 rb_erase(&t->rb_node, &rb_root);
512 static void show_entries_rb(void)
514 struct blk_io_trace *bit;
519 n = rb_first(&rb_root);
524 t = rb_entry(n, struct trace, rb_node);
528 if (cpu > max_cpus) {
529 fprintf(stderr, "CPU number too large (%d)\n", cpu);
533 if (genesis_time == 0)
534 genesis_time = bit->time;
535 bit->time -= genesis_time;
539 if (dump_trace(bit, &per_cpu_info[cpu]))
542 } while ((n = rb_next(n)) != NULL);
545 static int read_data(int fd, void *buffer, int bytes, int block)
547 int ret, bytes_left, fl;
550 fl = fcntl(fd, F_GETFL);
553 fcntl(fd, F_SETFL, fl | O_NONBLOCK);
555 fcntl(fd, F_SETFL, fl & ~O_NONBLOCK);
559 while (bytes_left > 0) {
560 ret = read(fd, p, bytes_left);
576 static int do_file(void)
580 for (i = 0, nfiles = 0;; i++, nfiles++) {
581 struct per_cpu_info *pci;
585 pci = get_cpu_info(i);
588 snprintf(pci->fname, sizeof(pci->fname)-1,"%s_out.%d", dev, i);
589 if (stat(pci->fname, &st) < 0)
594 printf("Processing %s\n", pci->fname);
596 tb = malloc(st.st_size);
598 pci->fd = open(pci->fname, O_RDONLY);
604 if (read_data(pci->fd, tb, st.st_size, 1))
607 if (sort_entries(tb, st.st_size, ~0U) == -1)
611 printf("\t%2d %10s %15d\n", i, pci->fname, pci->nelems);
616 fprintf(stderr, "No files found\n");
624 static void resize_buffer(void **buffer, long *old_size)
626 long cur_size = *old_size;
630 ptr = malloc(*old_size);
631 memcpy(ptr, *buffer, cur_size);
636 static int read_sort_events(int fd, void **buffer)
638 long offset, max_offset;
641 max_offset = 128 * sizeof(struct blk_io_trace);
642 *buffer = malloc(max_offset);
647 struct blk_io_trace *t;
650 if (max_offset - offset < sizeof(*t))
651 resize_buffer(buffer, &max_offset);
653 if (read_data(fd, *buffer + offset, sizeof(*t), !events)) {
661 t = *buffer + offset;
662 offset += sizeof(*t);
664 pdu_len = be16_to_cpu(t->pdu_len);
666 if (max_offset - offset < pdu_len)
667 resize_buffer(buffer, &max_offset);
669 if (read_data(fd, *buffer + offset, pdu_len, 1))
674 } while (!is_done());
679 static int do_stdin(void)
684 fd = dup(STDIN_FILENO);
688 events = read_sort_events(fd, &ptr);
692 sort_entries(ptr, ~0UL, events);
702 static void flush_output(void)
706 for (i = 0; i < max_cpus; i++) {
707 struct per_cpu_info *pci = &per_cpu_info[i];
717 static void handle_sigint(int sig)
723 static void usage(char *prog)
725 fprintf(stderr, "Usage: %s -i <name> [-o <output>]\n", prog);
728 int main(int argc, char *argv[])
732 while ((c = getopt_long(argc, argv, S_OPTS, l_opts, NULL)) != -1) {
735 dev = strdup(optarg);
738 output_name = strdup(optarg);
751 memset(&rb_root, 0, sizeof(rb_root));
753 signal(SIGINT, handle_sigint);
754 signal(SIGHUP, handle_sigint);
755 signal(SIGTERM, handle_sigint);
757 if (!strcmp(dev, "-"))