blkparse.c

   1 #include <sys/types.h>
   2 #include <sys/stat.h>
   3 #include <unistd.h>
   4 #include <stdio.h>
   5 #include <fcntl.h>
   6 #include <stdlib.h>
   7 #include <string.h>
   8
   9 #include "blktrace.h"
  10 #include "rbtree.h"
  11
  12 #define MAX_CPUS        (512)
  13
  14 struct per_file_info {
  15         int cpu;
  16         int nelems;
  17         struct stat stat;
  18
  19         int fd;
  20         char *fname;
  21         FILE *ofp;
  22         char *ofname;
  23         int dfd;
  24         char *dname;
  25
  26         void *trace_buf;
  27
  28         unsigned long long start_time;
  29 };
  30
  31 static struct rb_root rb_root;
  32
  33 struct trace {
  34         struct blk_io_trace *bit;
  35         struct rb_node rb_node;
  36 };
  37
  38 struct per_file_info per_file_info[MAX_CPUS];
  39 struct per_file_info *cur_file;
  40
  41 static unsigned long qreads, qwrites, creads, cwrites, mreads, mwrites;
  42 static unsigned long long qread_kb, qwrite_kb, cread_kb, cwrite_kb;
  43 static unsigned long long events, missed_events;
  44
  45 static inline void account_m(int rw, unsigned int bytes)
  46 {
  47         if (rw) {
  48                 mwrites++;
  49                 qwrite_kb += bytes >> 10;
  50         } else {
  51                 mreads++;
  52                 qread_kb += bytes >> 10;
  53         }
  54 }
  55
  56 static inline void account_q(int rw, unsigned int bytes)
  57 {
  58         if (rw) {
  59                 qwrites++;
  60                 qwrite_kb += bytes >> 10;
  61         } else {
  62                 qreads++;
  63                 qread_kb += bytes >> 10;
  64         }
  65 }
  66
  67 static inline void account_c(int rw, unsigned int bytes)
  68 {
  69         if (rw) {
  70                 cwrites++;
  71                 cwrite_kb += bytes >> 10;
  72         } else {
  73                 creads++;
  74                 cread_kb += bytes >> 10;
  75         }
  76 }
  77
  78 static void output(char *s)
  79 {
  80         printf("%s", s);
  81         fprintf(cur_file->ofp,"%s",s);
  82 }
  83
  84 static char hstring[256];
  85 static char tstring[256];
  86
  87 static inline char *setup_header(struct blk_io_trace *t, char act)
  88 {
  89         int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
  90         int b = t->action & BLK_TC_ACT(BLK_TC_BARRIER);
  91         int s = t->action & BLK_TC_ACT(BLK_TC_SYNC);
  92         char rwbs[4];
  93         int i = 0;
  94
  95         if (w)
  96                 rwbs[i++] = 'W';
  97         else
  98                 rwbs[i++] = 'R';
  99         if (b)
 100                 rwbs[i++] = 'B';
 101         if (s)
 102                 rwbs[i++] = 'S';
 103
 104         rwbs[i] = '\0';
 105
 106         sprintf(hstring, "%3d %15ld %12Lu %5u %c %3s", cur_file->cpu,
 107                 (unsigned long)t->sequence, (unsigned long long)t->time, t->pid,
 108                 act, rwbs);
 109
 110         return hstring;
 111 }
 112
 113 static void log_complete(struct blk_io_trace *t, char act)
 114 {
 115         sprintf(tstring,"%s %Lu + %u [%d]\n", setup_header(t, act),
 116                 (unsigned long long)t->sector, t->bytes >> 9, t->error);
 117         output(tstring);
 118 }
 119
 120 static void log_queue(struct blk_io_trace *t, char act)
 121 {
 122         sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act),
 123                 (unsigned long long)t->sector, t->bytes >> 9);
 124         output(tstring);
 125 }
 126
 127 static void log_issue(struct blk_io_trace *t, char act)
 128 {
 129         sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act),
 130                 (unsigned long long)t->sector, t->bytes >> 9);
 131         output(tstring);
 132 }
 133
 134 static void log_merge(struct blk_io_trace *t, char act)
 135 {
 136         sprintf(tstring,"%s   %Lu + %u\n", setup_header(t, act),
 137                 (unsigned long long)t->sector, t->bytes >> 9);
 138         output(tstring);
 139 }
 140
 141 static void log_generic(struct blk_io_trace *t, char act)
 142 {
 143         sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act),
 144                 (unsigned long long)t->sector, t->bytes >> 9);
 145         output(tstring);
 146 }
 147
 148 static void log_pc(struct blk_io_trace *t, char act)
 149 {
 150         int i, ret;
 151         unsigned char buf[64];
 152
 153         sprintf(tstring,"%s\n", setup_header(t, act));
 154         output(tstring);
 155
 156         if (t->pdu_len > sizeof(buf)) {
 157                 fprintf(stderr, "Payload too large %d\n", t->pdu_len);
 158                 return;
 159         }
 160
 161         ret = read(cur_file->dfd, buf, t->pdu_len);
 162         if (ret != t->pdu_len) {
 163                 fprintf(stderr,"read(%d) failed on %s - %d\n", t->pdu_len,
 164                         cur_file->dname, ret);
 165                 exit(1);
 166         }
 167
 168         for (i = 0; i < t->pdu_len; i++) {
 169                 sprintf(tstring,"%02x ", buf[i]);
 170                 output(tstring);
 171         }
 172
 173         if (act == 'C') {
 174                 sprintf(tstring,"[%d]", t->error);
 175                 output(tstring);
 176         }
 177
 178         printf("\n");
 179 }
 180
 181 static void dump_trace_pc(struct blk_io_trace *t)
 182 {
 183         switch (t->action & 0xffff) {
 184                 case __BLK_TA_QUEUE:
 185                         log_generic(t, 'Q');
 186                         break;
 187                 case __BLK_TA_GETRQ:
 188                         log_generic(t, 'G');
 189                         break;
 190                 case __BLK_TA_SLEEPRQ:
 191                         log_generic(t, 'S');
 192                         break;
 193                 case __BLK_TA_REQUEUE:
 194                         log_generic(t, 'R');
 195                         break;
 196                 case __BLK_TA_ISSUE:
 197                         log_pc(t, 'D');
 198                         break;
 199                 case __BLK_TA_COMPLETE:
 200                         log_pc(t, 'C');
 201                         break;
 202                 default:
 203                         fprintf(stderr, "Bad pc action %x\n", t->action);
 204                         return;
 205         }
 206
 207         events++;
 208 }
 209
 210 static void dump_trace_fs(struct blk_io_trace *t)
 211 {
 212         int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
 213
 214         switch (t->action & 0xffff) {
 215                 case __BLK_TA_QUEUE:
 216                         account_q(w, t->bytes);
 217                         log_queue(t, 'Q');
 218                         break;
 219                 case __BLK_TA_BACKMERGE:
 220                         account_m(w, t->bytes);
 221                         log_merge(t, 'M');
 222                         break;
 223                 case __BLK_TA_FRONTMERGE:
 224                         account_m(w, t->bytes);
 225                         log_merge(t, 'F');
 226                         break;
 227                 case __BLK_TA_GETRQ:
 228                         log_generic(t, 'G');
 229                         break;
 230                 case __BLK_TA_SLEEPRQ:
 231                         log_generic(t, 'S');
 232                         break;
 233                 case __BLK_TA_REQUEUE:
 234                         log_queue(t, 'R');
 235                         break;
 236                 case __BLK_TA_ISSUE:
 237                         log_issue(t, 'D');
 238                         break;
 239                 case __BLK_TA_COMPLETE:
 240                         account_c(w, t->bytes);
 241                         log_complete(t, 'C');
 242                         break;
 243                 default:
 244                         fprintf(stderr, "Bad fs action %x\n", t->action);
 245                         return;
 246         }
 247
 248         events++;
 249 }
 250
 251 static void dump_trace(struct blk_io_trace *t)
 252 {
 253         if (t->action & BLK_TC_ACT(BLK_TC_PC))
 254                 dump_trace_pc(t);
 255         else
 256                 dump_trace_fs(t);
 257 }
 258
 259 static void show_stats(void)
 260 {
 261         printf("\nReads:");
 262         printf("\tQueued:    %'8lu, %'8LuKiB\n", qreads, qread_kb);
 263         printf("\tCompleted: %'8lu, %'8LuKiB\n", creads, cread_kb);
 264         printf("\tMerges:    %'8lu\n", mreads);
 265
 266         printf("Writes:");
 267         printf("\tQueued:    %'8lu, %'8LuKiB\n", qwrites, qwrite_kb);
 268         printf("\tCompleted: %'8lu, %'8LuKiB\n", cwrites, cwrite_kb);
 269         printf("\tMerges:    %'8lu\n", mwrites);
 270
 271         printf("Events: %'Lu\n", events);
 272         printf("Missed events: %'Lu\n", missed_events);
 273 }
 274
 275 static inline int trace_rb_insert(struct trace *t)
 276 {
 277         struct rb_node **p = &rb_root.rb_node;
 278         struct rb_node *parent = NULL;
 279         struct trace *__t;
 280
 281         while (*p) {
 282                 parent = *p;
 283                 __t = rb_entry(parent, struct trace, rb_node);
 284
 285                 if (t->bit->sequence < __t->bit->sequence)
 286                         p = &(*p)->rb_left;
 287                 else if (t->bit->sequence > __t->bit->sequence)
 288                         p = &(*p)->rb_right;
 289                 else {
 290                         fprintf(stderr, "sequence alias %u!\n", t->bit->sequence);
 291                         return 1;
 292                 }
 293         }
 294
 295         rb_link_node(&t->rb_node, parent, p);
 296         rb_insert_color(&t->rb_node, &rb_root);
 297         return 0;
 298 }
 299
 300 static int sort_entries(void *traces, unsigned long offset)
 301 {
 302         struct blk_io_trace *bit;
 303         struct trace *t;
 304         void *start = traces;
 305         int nelems = 0;
 306
 307         memset(&rb_root, 0, sizeof(rb_root));
 308
 309         do {
 310                 bit = traces;
 311                 t = malloc(sizeof(*t));
 312                 t->bit = bit;
 313                 memset(&t->rb_node, 0, sizeof(t->rb_node));
 314
 315                 if (trace_rb_insert(t))
 316                         return -1;
 317
 318                 traces += sizeof(*bit) + bit->pdu_len;
 319                 nelems++;
 320         } while (traces < start + offset);
 321
 322         return nelems;
 323 }
 324
 325 static void show_entries(void)
 326 {
 327         struct blk_io_trace *bit;
 328         struct rb_node *n;
 329         struct trace *t;
 330         int cpu;
 331
 332         n = rb_first(&rb_root);
 333         if (!n)
 334                 return;
 335
 336         do {
 337                 t = rb_entry(n, struct trace, rb_node);
 338                 bit = t->bit;
 339
 340                 cpu = bit->magic;
 341                 if (cpu >= MAX_CPUS) {
 342                         fprintf(stderr, "CPU number too large (%d)\n", cpu);
 343                         return;
 344                 }
 345
 346                 cur_file = &per_file_info[cpu];
 347
 348                 /*
 349                  * offset time by first trace event.
 350                  *
 351                  * NOTE: This is *cpu* relative, thus you can not
 352                  * compare times ACROSS cpus.
 353                  */
 354                 if (cur_file->start_time == 0)
 355                         cur_file->start_time = bit->time;
 356
 357                 bit->time -= cur_file->start_time;
 358
 359                 dump_trace(bit);
 360         } while ((n = rb_next(n)) != NULL);
 361 }
 362
 363 int main(int argc, char *argv[])
 364 {
 365         struct per_file_info *pfi;
 366         int i, nfiles, ret;
 367         char *dev;
 368
 369         if (argc != 2) {
 370                 fprintf(stderr, "Usage %s <dev>\n", argv[0]);
 371                 return 1;
 372         }
 373
 374         dev = argv[1];
 375
 376         nfiles = 0;
 377         for (i = 0, pfi = &per_file_info[0]; i < MAX_CPUS; i++, pfi++) {
 378                 pfi->cpu = i;
 379                 pfi->start_time = 0;
 380
 381                 pfi->fname = malloc(128);
 382                 sprintf(pfi->fname, "%s_out.%d", dev, i);
 383                 if (stat(pfi->fname, &pfi->stat) < 0)
 384                         break;
 385
 386                 pfi->dname = malloc(128);
 387                 snprintf(pfi->dname, 127, "%s_dat.%d", dev, i);
 388                 pfi->dfd = open(pfi->dname, O_RDONLY);
 389                 if (pfi->dfd < 0) {
 390                         perror(pfi->dname);
 391                         break;
 392                 }
 393
 394                 pfi->ofname = malloc(128);
 395                 snprintf(pfi->ofname, 127, "%s_log.%d", dev, i);
 396                 pfi->ofp = fopen(pfi->ofname, "w");
 397                 if (pfi->ofp == NULL) {
 398                         perror(pfi->ofname);
 399                         break;
 400                 }
 401
 402                 printf("Processing %s\n", pfi->fname);
 403
 404                 pfi->trace_buf = malloc(pfi->stat.st_size);
 405
 406                 pfi->fd = open(pfi->fname, O_RDONLY);
 407                 if (pfi->fd < 0) {
 408                         perror(pfi->fname);
 409                         break;
 410                 }
 411                 if (read(pfi->fd, pfi->trace_buf, pfi->stat.st_size) != pfi->stat.st_size) {
 412                         fprintf(stderr, "error reading\n");
 413                         break;
 414                 }
 415
 416                 ret = sort_entries(pfi->trace_buf, pfi->stat.st_size);
 417                 if (ret == -1)
 418                         break;
 419
 420                 close(pfi->fd);
 421                 nfiles++;
 422                 pfi->nelems = ret;
 423                 printf("\t%2d %10s %15d\n", i, pfi->fname, pfi->nelems);
 424
 425         }
 426
 427         if (nfiles) {
 428                 show_entries();
 429                 show_stats();
 430                 return 0;
 431         }
 432
 433         fprintf(stderr, "No files found\n");
 434         return 1;
 435 }