[PATCH] Missing ->cpu endianness conversion
[blktrace.git] / blkparse.c
... / ...
CommitLineData
1/*
2 * block queue tracing parse application
3 *
4 * Copyright (C) 2005 Jens Axboe <axboe@suse.de>
5 *
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.
10 *
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.
15 *
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
19 *
20 */
21#include <sys/types.h>
22#include <sys/stat.h>
23#include <unistd.h>
24#include <stdio.h>
25#include <fcntl.h>
26#include <stdlib.h>
27#include <string.h>
28#include <getopt.h>
29#include <errno.h>
30#include <signal.h>
31
32#include "blktrace.h"
33#include "rbtree.h"
34
35#define MAX_CPUS (512)
36
37#define SECONDS(x) ((unsigned long long)(x) / 1000000000)
38#define NANO_SECONDS(x) ((unsigned long long)(x) % 1000000000)
39
40static int backwards;
41static unsigned long long genesis_time, last_reported_time;
42
43struct per_cpu_info {
44 int cpu;
45 int nelems;
46
47 int fd;
48 char fname[128];
49
50 FILE *ofp;
51 char ofname[128];
52
53 unsigned long qreads, qwrites, creads, cwrites, mreads, mwrites;
54 unsigned long ireads, iwrites;
55 unsigned long long qread_kb, qwrite_kb, cread_kb, cwrite_kb;
56 unsigned long long iread_kb, iwrite_kb;
57};
58
59#define S_OPTS "i:o:"
60static struct option l_opts[] = {
61 {
62 .name = "input",
63 .has_arg = 1,
64 .flag = NULL,
65 .val = 'i'
66 },
67 {
68 .name = "output",
69 .has_arg = 1,
70 .flag = NULL,
71 .val = 'o'
72 },
73 {
74 .name = NULL,
75 .has_arg = 0,
76 .flag = NULL,
77 .val = 0
78 }
79};
80
81static struct rb_root rb_root;
82
83struct trace {
84 struct blk_io_trace *bit;
85 struct rb_node rb_node;
86};
87
88static struct per_cpu_info per_cpu_info[MAX_CPUS];
89
90static unsigned long long events;
91
92static int max_cpus;
93
94static char *dev, *output_name;
95
96#define is_done() (*(volatile int *)(&done))
97static volatile int done;
98
99static inline void check_time(struct blk_io_trace *bit)
100{
101 unsigned long long this = bit->time;
102 unsigned long long last = last_reported_time;
103
104 backwards = (this < last) ? 'B' : ' ';
105 last_reported_time = this;
106}
107
108static inline void account_m(struct per_cpu_info *pci, int rw,
109 unsigned int bytes)
110{
111 if (rw) {
112 pci->mwrites++;
113 pci->qwrite_kb += bytes >> 10;
114 } else {
115 pci->mreads++;
116 pci->qread_kb += bytes >> 10;
117 }
118}
119
120static inline void account_q(struct per_cpu_info *pci, int rw,
121 unsigned int bytes)
122{
123 if (rw) {
124 pci->qwrites++;
125 pci->qwrite_kb += bytes >> 10;
126 } else {
127 pci->qreads++;
128 pci->qread_kb += bytes >> 10;
129 }
130}
131
132static inline void account_c(struct per_cpu_info *pci, int rw,
133 unsigned int bytes)
134{
135 if (rw) {
136 pci->cwrites++;
137 pci->cwrite_kb += bytes >> 10;
138 } else {
139 pci->creads++;
140 pci->cread_kb += bytes >> 10;
141 }
142}
143
144static inline void account_i(struct per_cpu_info *pci, int rw,
145 unsigned int bytes)
146{
147 if (rw) {
148 pci->iwrites++;
149 pci->iwrite_kb += bytes >> 10;
150 } else {
151 pci->ireads++;
152 pci->iread_kb += bytes >> 10;
153 }
154}
155
156static void output(struct per_cpu_info *pci, char *s)
157{
158 printf("%s", s);
159
160 if (pci->ofp)
161 fprintf(pci->ofp, "%s", s);
162}
163
164static char hstring[256];
165static char tstring[256];
166
167static inline char *setup_header(struct per_cpu_info *pci,
168 struct blk_io_trace *t, char act)
169{
170 int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
171 int b = t->action & BLK_TC_ACT(BLK_TC_BARRIER);
172 int s = t->action & BLK_TC_ACT(BLK_TC_SYNC);
173 char rwbs[4];
174 int i = 0;
175
176 if (w)
177 rwbs[i++] = 'W';
178 else
179 rwbs[i++] = 'R';
180 if (b)
181 rwbs[i++] = 'B';
182 if (s)
183 rwbs[i++] = 'S';
184
185 rwbs[i] = '\0';
186
187 sprintf(hstring, "%c %3d %15ld %5Lu.%09Lu %5u %c %3s", backwards,
188 pci->cpu,
189 (unsigned long)t->sequence, SECONDS(t->time),
190 NANO_SECONDS(t->time), t->pid, act, rwbs);
191
192 return hstring;
193}
194
195static void log_complete(struct per_cpu_info *pci, struct blk_io_trace *t,
196 char act)
197{
198 sprintf(tstring,"%s %Lu + %u [%d]\n", setup_header(pci, t, act),
199 (unsigned long long)t->sector, t->bytes >> 9, t->error);
200 output(pci, tstring);
201}
202
203static void log_queue(struct per_cpu_info *pci, struct blk_io_trace *t,
204 char act)
205{
206 sprintf(tstring,"%s %Lu + %u\n", setup_header(pci, t, act),
207 (unsigned long long)t->sector, t->bytes >> 9);
208 output(pci, tstring);
209}
210
211static void log_issue(struct per_cpu_info *pci, struct blk_io_trace *t,
212 char act)
213{
214 sprintf(tstring,"%s %Lu + %u\n", setup_header(pci, t, act),
215 (unsigned long long)t->sector, t->bytes >> 9);
216 output(pci, tstring);
217}
218
219static void log_merge(struct per_cpu_info *pci, struct blk_io_trace *t,
220 char act)
221{
222 sprintf(tstring,"%s %Lu + %u\n", setup_header(pci, t, act),
223 (unsigned long long)t->sector, t->bytes >> 9);
224 output(pci, tstring);
225}
226
227static void log_generic(struct per_cpu_info *pci, struct blk_io_trace *t,
228 char act)
229{
230 sprintf(tstring,"%s %Lu + %u\n", setup_header(pci, t, act),
231 (unsigned long long)t->sector, t->bytes >> 9);
232 output(pci, tstring);
233}
234
235static int log_pc(struct per_cpu_info *pci, struct blk_io_trace *t, char act)
236{
237 unsigned char *buf;
238 int i;
239
240 sprintf(tstring,"%s ", setup_header(pci, t, act));
241 output(pci, tstring);
242
243 buf = (unsigned char *) t + sizeof(*t);
244 for (i = 0; i < t->pdu_len; i++) {
245 sprintf(tstring,"%02x ", buf[i]);
246 output(pci, tstring);
247 }
248
249 if (act == 'C') {
250 sprintf(tstring,"[%d]", t->error);
251 output(pci, tstring);
252 }
253
254 printf("\n");
255 return 0;
256}
257
258static int dump_trace_pc(struct blk_io_trace *t, struct per_cpu_info *pci)
259{
260 int ret = 0;
261
262 switch (t->action & 0xffff) {
263 case __BLK_TA_QUEUE:
264 log_generic(pci, t, 'Q');
265 break;
266 case __BLK_TA_GETRQ:
267 log_generic(pci, t, 'G');
268 break;
269 case __BLK_TA_SLEEPRQ:
270 log_generic(pci, t, 'S');
271 break;
272 case __BLK_TA_REQUEUE:
273 log_generic(pci, t, 'R');
274 break;
275 case __BLK_TA_ISSUE:
276 ret = log_pc(pci, t, 'D');
277 break;
278 case __BLK_TA_COMPLETE:
279 log_pc(pci, t, 'C');
280 break;
281 default:
282 fprintf(stderr, "Bad pc action %x\n", t->action);
283 ret = 1;
284 break;
285 }
286
287 return ret;
288}
289
290static void dump_trace_fs(struct blk_io_trace *t, struct per_cpu_info *pci)
291{
292 int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
293
294 switch (t->action & 0xffff) {
295 case __BLK_TA_QUEUE:
296 account_q(pci, w, t->bytes);
297 log_queue(pci, t, 'Q');
298 break;
299 case __BLK_TA_BACKMERGE:
300 account_m(pci, w, t->bytes);
301 log_merge(pci, t, 'M');
302 break;
303 case __BLK_TA_FRONTMERGE:
304 account_m(pci, w, t->bytes);
305 log_merge(pci, t, 'F');
306 break;
307 case __BLK_TA_GETRQ:
308 log_generic(pci, t, 'G');
309 break;
310 case __BLK_TA_SLEEPRQ:
311 log_generic(pci, t, 'S');
312 break;
313 case __BLK_TA_REQUEUE:
314 account_c(pci, w, -t->bytes);
315 log_queue(pci, t, 'R');
316 break;
317 case __BLK_TA_ISSUE:
318 account_i(pci, w, t->bytes);
319 log_issue(pci, t, 'D');
320 break;
321 case __BLK_TA_COMPLETE:
322 account_c(pci, w, t->bytes);
323 log_complete(pci, t, 'C');
324 break;
325 default:
326 fprintf(stderr, "Bad fs action %x\n", t->action);
327 break;
328 }
329}
330
331static int dump_trace(struct blk_io_trace *t, struct per_cpu_info *pci)
332{
333 int ret = 0;
334
335 if (output_name && !pci->ofp) {
336 snprintf(pci->ofname, sizeof(pci->ofname) - 1,
337 "%s_log.%d", output_name, pci->cpu);
338
339 pci->ofp = fopen(pci->ofname, "w");
340 if (pci->ofp == NULL) {
341 perror(pci->ofname);
342 return 1;
343 }
344 }
345
346 if (t->action & BLK_TC_ACT(BLK_TC_PC))
347 ret = dump_trace_pc(t, pci);
348 else
349 dump_trace_fs(t, pci);
350
351 events++;
352 return ret;
353}
354
355static void dump_pci_stats(struct per_cpu_info *pci)
356{
357 printf("\tReads:\n");
358 printf("\t\tQueued: %'8lu, %'8LuKiB\n", pci->qreads, pci->qread_kb);
359 printf("\t\tDispatched %'8lu, %'8LuKiB\n", pci->ireads, pci->iread_kb);
360 printf("\t\tCompleted: %'8lu, %'8LuKiB\n", pci->creads, pci->cread_kb);
361 printf("\t\tMerges: %'8lu\n", pci->mreads);
362
363 printf("\tWrites:\n");
364 printf("\t\tQueued: %'8lu, %'8LuKiB\n", pci->qwrites,pci->qwrite_kb);
365 printf("\t\tDispatched %'8lu, %'8LuKiB\n", pci->iwrites,pci->iwrite_kb);
366 printf("\t\tCompleted: %'8lu, %'8LuKiB\n", pci->cwrites,pci->cwrite_kb);
367 printf("\t\tMerges: %'8lu\n", pci->mwrites);
368}
369
370static void show_stats(void)
371{
372 struct per_cpu_info foo, *pci;
373 int i, pci_events = 0;
374
375 memset(&foo, 0, sizeof(foo));
376
377 for (i = 0; i < MAX_CPUS; i++) {
378 pci = &per_cpu_info[i];
379
380 if (!pci->nelems)
381 continue;
382
383 foo.qreads += pci->qreads;
384 foo.qwrites += pci->qwrites;
385 foo.creads += pci->creads;
386 foo.cwrites += pci->cwrites;
387 foo.mreads += pci->mreads;
388 foo.mwrites += pci->mwrites;
389 foo.qread_kb += pci->qread_kb;
390 foo.qwrite_kb += pci->qwrite_kb;
391 foo.cread_kb += pci->cread_kb;
392 foo.cwrite_kb += pci->cwrite_kb;
393
394 printf("CPU%d:\n", i);
395 dump_pci_stats(pci);
396 pci_events++;
397 }
398
399 if (pci_events > 1) {
400 printf("Total:\n");
401 dump_pci_stats(&foo);
402 }
403
404 printf("Events: %'Lu\n", events);
405}
406
407static inline int trace_rb_insert(struct trace *t)
408{
409 struct rb_node **p = &rb_root.rb_node;
410 struct rb_node *parent = NULL;
411 struct trace *__t;
412
413 while (*p) {
414 parent = *p;
415 __t = rb_entry(parent, struct trace, rb_node);
416
417 if (t->bit->sequence < __t->bit->sequence)
418 p = &(*p)->rb_left;
419 else if (t->bit->sequence > __t->bit->sequence)
420 p = &(*p)->rb_right;
421 else {
422 fprintf(stderr, "sequence alias!\n");
423 return 1;
424 }
425 }
426
427 rb_link_node(&t->rb_node, parent, p);
428 rb_insert_color(&t->rb_node, &rb_root);
429 return 0;
430}
431
432static int sort_entries(void *traces, unsigned long offset, int nr)
433{
434 struct per_cpu_info *pci;
435 struct blk_io_trace *bit;
436 struct trace *t;
437 void *start = traces;
438 int nelems = 0;
439
440 while (traces - start <= offset - sizeof(*bit)) {
441 if (!nr)
442 break;
443
444 bit = traces;
445
446 t = malloc(sizeof(*t));
447 t->bit = bit;
448 memset(&t->rb_node, 0, sizeof(t->rb_node));
449
450 trace_to_cpu(bit);
451
452 if (verify_trace(bit))
453 break;
454
455 pci = &per_cpu_info[bit->cpu];
456
457 pci->nelems++;
458
459 if (trace_rb_insert(t))
460 return -1;
461
462 traces += sizeof(*bit) + bit->pdu_len;
463 nelems++;
464 nr--;
465 }
466
467 return nelems;
468}
469
470static void free_entries_rb(void)
471{
472 struct rb_node *n;
473
474 while ((n = rb_first(&rb_root)) != NULL) {
475 struct trace *t = rb_entry(n, struct trace, rb_node);
476
477 rb_erase(&t->rb_node, &rb_root);
478 free(t);
479 }
480}
481
482static void show_entries_rb(void)
483{
484 struct blk_io_trace *bit;
485 struct rb_node *n;
486 struct trace *t;
487 int cpu;
488
489 n = rb_first(&rb_root);
490 if (!n)
491 return;
492
493 do {
494 t = rb_entry(n, struct trace, rb_node);
495 bit = t->bit;
496
497 cpu = bit->cpu;
498 if (cpu > max_cpus) {
499 fprintf(stderr, "CPU number too large (%d)\n", cpu);
500 break;
501 }
502
503 if (genesis_time == 0)
504 genesis_time = bit->time;
505 bit->time -= genesis_time;
506
507 check_time(bit);
508
509 if (dump_trace(bit, &per_cpu_info[cpu]))
510 break;
511
512 } while ((n = rb_next(n)) != NULL);
513}
514
515static int read_data(int fd, void *buffer, int bytes, int block)
516{
517 int ret, bytes_left, fl;
518 void *p;
519
520 fl = fcntl(fd, F_GETFL);
521
522 if (!block)
523 fcntl(fd, F_SETFL, fl | O_NONBLOCK);
524 else
525 fcntl(fd, F_SETFL, fl & ~O_NONBLOCK);
526
527 bytes_left = bytes;
528 p = buffer;
529 while (bytes_left > 0) {
530 ret = read(fd, p, bytes_left);
531 if (!ret)
532 return 1;
533 else if (ret < 0) {
534 if (errno != EAGAIN)
535 perror("read");
536 return -1;
537 } else {
538 p += ret;
539 bytes_left -= ret;
540 }
541 }
542
543 return 0;
544}
545
546static int do_file(void)
547{
548 int i, ret, nfiles;
549
550 nfiles = 0;
551 max_cpus = 0;
552 for (i = 0; i < MAX_CPUS; i++, nfiles++, max_cpus++) {
553 struct per_cpu_info *pci = &per_cpu_info[i];
554 struct stat st;
555 void *tb;
556
557 pci->cpu = i;
558 pci->ofp = NULL;
559
560 snprintf(pci->fname, sizeof(pci->fname)-1,"%s_out.%d", dev, i);
561 if (stat(pci->fname, &st) < 0)
562 break;
563 if (!st.st_size)
564 continue;
565
566 printf("Processing %s\n", pci->fname);
567
568 tb = malloc(st.st_size);
569
570 pci->fd = open(pci->fname, O_RDONLY);
571 if (pci->fd < 0) {
572 perror(pci->fname);
573 break;
574 }
575
576 if (read_data(pci->fd, tb, st.st_size, 1))
577 break;
578
579 ret = sort_entries(tb, st.st_size, ~0U);
580 if (ret == -1)
581 break;
582
583 close(pci->fd);
584 printf("\t%2d %10s %15d\n", i, pci->fname, pci->nelems);
585
586 }
587
588 if (!nfiles) {
589 fprintf(stderr, "No files found\n");
590 return 1;
591 }
592
593 show_entries_rb();
594 return 0;
595}
596
597static void resize_buffer(void **buffer, long *old_size)
598{
599 long cur_size = *old_size;
600 void *ptr;
601
602 *old_size *= 2;
603 ptr = malloc(*old_size);
604 memcpy(ptr, *buffer, cur_size);
605 free(*buffer);
606 *buffer = ptr;
607}
608
609static int read_sort_events(int fd, void **buffer)
610{
611 long offset, max_offset;
612 int events;
613
614 max_offset = 128 * sizeof(struct blk_io_trace);
615 *buffer = malloc(max_offset);
616 events = 0;
617 offset = 0;
618
619 do {
620 struct blk_io_trace *t;
621 int pdu_len;
622
623 if (max_offset - offset < sizeof(*t))
624 resize_buffer(buffer, &max_offset);
625
626 if (read_data(fd, *buffer + offset, sizeof(*t), !events)) {
627 if (events)
628 break;
629
630 usleep(1000);
631 continue;
632 }
633
634 t = *buffer + offset;
635 offset += sizeof(*t);
636
637 pdu_len = be16_to_cpu(t->pdu_len);
638
639 if (max_offset - offset < pdu_len)
640 resize_buffer(buffer, &max_offset);
641
642 if (read_data(fd, *buffer + offset, pdu_len, 1))
643 break;
644
645 offset += pdu_len;
646 events++;
647 } while (!is_done());
648
649 return events;
650}
651
652static int do_stdin(void)
653{
654 int fd;
655 void *ptr;
656
657 fd = dup(STDIN_FILENO);
658 do {
659 int events;
660
661 events = read_sort_events(fd, &ptr);
662 if (!events)
663 break;
664
665 sort_entries(ptr, ~0UL, events);
666 show_entries_rb();
667 free_entries_rb();
668 } while (1);
669
670 close(fd);
671 free(ptr);
672 return 0;
673}
674
675static void flush_output(void)
676{
677 int i;
678
679 for (i = 0; i < MAX_CPUS; i++) {
680 struct per_cpu_info *pci = &per_cpu_info[i];
681
682 if (pci->ofp) {
683 fflush(pci->ofp);
684 fclose(pci->ofp);
685 pci->ofp = NULL;
686 }
687 }
688}
689
690static void handle_sigint(int sig)
691{
692 done = 1;
693 flush_output();
694}
695
696static void usage(char *prog)
697{
698 fprintf(stderr, "Usage: %s -i <name> [-o <output>]\n", prog);
699}
700
701int main(int argc, char *argv[])
702{
703 int c, ret;
704
705 while ((c = getopt_long(argc, argv, S_OPTS, l_opts, NULL)) != -1) {
706 switch (c) {
707 case 'i':
708 dev = strdup(optarg);
709 break;
710 case 'o':
711 output_name = strdup(optarg);
712 break;
713 default:
714 usage(argv[0]);
715 return 1;
716 }
717 }
718
719 if (!dev) {
720 usage(argv[0]);
721 return 1;
722 }
723
724 memset(per_cpu_info, 0, sizeof(per_cpu_info));
725 memset(&rb_root, 0, sizeof(rb_root));
726
727 signal(SIGINT, handle_sigint);
728 signal(SIGHUP, handle_sigint);
729 signal(SIGTERM, handle_sigint);
730
731 if (!strcmp(dev, "-"))
732 ret = do_stdin();
733 else
734 ret = do_file();
735
736 show_stats();
737 flush_output();
738 return ret;
739}