blkparse.c

   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
  29 #include "blktrace.h"
  30 #include "rbtree.h"
  31
  32 #define MAX_CPUS        (512)
  33
  34 #define SECONDS(x)      ((unsigned long long)(x) / 1000000000)
  35 #define NANO_SECONDS(x) ((unsigned long long)(x) % 1000000000)
  36
  37 int backwards;
  38 unsigned long long genesis_time, last_reported_time;
  39 struct per_file_info {
  40         int cpu;
  41         int nelems;
  42
  43         int fd;
  44         char fname[128];
  45
  46         FILE *ofp;
  47         char ofname[128];
  48
  49         unsigned long qreads, qwrites, creads, cwrites, mreads, mwrites;
  50         unsigned long ireads, iwrites;
  51         unsigned long long qread_kb, qwrite_kb, cread_kb, cwrite_kb;
  52         unsigned long long iread_kb, iwrite_kb;
  53 };
  54
  55 static struct rb_root rb_root;
  56
  57 struct trace {
  58         struct blk_io_trace *bit;
  59         unsigned int cpu;
  60         struct rb_node rb_node;
  61 };
  62
  63 static struct per_file_info per_file_info[MAX_CPUS];
  64 static struct per_file_info *cur_file;
  65
  66 static unsigned long long events;
  67
  68 static int max_cpus;
  69
  70 static inline void check_time(struct blk_io_trace *bit)
  71 {
  72         unsigned long long this = bit->time;
  73         unsigned long long last = last_reported_time;
  74
  75         backwards = (this < last) ? 'B' : ' ';
  76         last_reported_time = this;
  77 }
  78
  79 static inline void account_m(struct per_file_info *pfi, int rw,
  80                              unsigned int bytes)
  81 {
  82         if (rw) {
  83                 pfi->mwrites++;
  84                 pfi->qwrite_kb += bytes >> 10;
  85         } else {
  86                 pfi->mreads++;
  87                 pfi->qread_kb += bytes >> 10;
  88         }
  89 }
  90
  91 static inline void account_q(struct per_file_info *pfi, int rw,
  92                              unsigned int bytes)
  93 {
  94         if (rw) {
  95                 pfi->qwrites++;
  96                 pfi->qwrite_kb += bytes >> 10;
  97         } else {
  98                 pfi->qreads++;
  99                 pfi->qread_kb += bytes >> 10;
 100         }
 101 }
 102
 103 static inline void account_c(struct per_file_info *pfi, int rw,
 104                              unsigned int bytes)
 105 {
 106         if (rw) {
 107                 pfi->cwrites++;
 108                 pfi->cwrite_kb += bytes >> 10;
 109         } else {
 110                 pfi->creads++;
 111                 pfi->cread_kb += bytes >> 10;
 112         }
 113 }
 114
 115 static inline void account_i(struct per_file_info *pfi, int rw,
 116                              unsigned int bytes)
 117 {
 118         if (rw) {
 119                 pfi->iwrites++;
 120                 pfi->iwrite_kb += bytes >> 10;
 121         } else {
 122                 pfi->ireads++;
 123                 pfi->iread_kb += bytes >> 10;
 124         }
 125 }
 126
 127 static void output(char *s)
 128 {
 129         printf("%s", s);
 130         fprintf(cur_file->ofp,"%s",s);
 131 }
 132
 133 static char hstring[256];
 134 static char tstring[256];
 135
 136 static inline char *setup_header(struct blk_io_trace *t, char act)
 137 {
 138         int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
 139         int b = t->action & BLK_TC_ACT(BLK_TC_BARRIER);
 140         int s = t->action & BLK_TC_ACT(BLK_TC_SYNC);
 141         char rwbs[4];
 142         int i = 0;
 143
 144         if (w)
 145                 rwbs[i++] = 'W';
 146         else
 147                 rwbs[i++] = 'R';
 148         if (b)
 149                 rwbs[i++] = 'B';
 150         if (s)
 151                 rwbs[i++] = 'S';
 152
 153         rwbs[i] = '\0';
 154
 155         sprintf(hstring, "%c %3d %15ld %5Lu.%09Lu %5u %c %3s", backwards,
 156                 cur_file->cpu,
 157                 (unsigned long)t->sequence, SECONDS(t->time),
 158                 NANO_SECONDS(t->time), t->pid, act, rwbs);
 159
 160         return hstring;
 161 }
 162
 163 static void log_complete(struct blk_io_trace *t, char act)
 164 {
 165         sprintf(tstring,"%s %Lu + %u [%d]\n", setup_header(t, act),
 166                 (unsigned long long)t->sector, t->bytes >> 9, t->error);
 167         output(tstring);
 168 }
 169
 170 static void log_queue(struct blk_io_trace *t, char act)
 171 {
 172         sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act),
 173                 (unsigned long long)t->sector, t->bytes >> 9);
 174         output(tstring);
 175 }
 176
 177 static void log_issue(struct blk_io_trace *t, char act)
 178 {
 179         sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act),
 180                 (unsigned long long)t->sector, t->bytes >> 9);
 181         output(tstring);
 182 }
 183
 184 static void log_merge(struct blk_io_trace *t, char act)
 185 {
 186         sprintf(tstring,"%s   %Lu + %u\n", setup_header(t, act),
 187                 (unsigned long long)t->sector, t->bytes >> 9);
 188         output(tstring);
 189 }
 190
 191 static void log_generic(struct blk_io_trace *t, char act)
 192 {
 193         sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act),
 194                 (unsigned long long)t->sector, t->bytes >> 9);
 195         output(tstring);
 196 }
 197
 198 static int log_pc(struct blk_io_trace *t, char act)
 199 {
 200         unsigned char *buf;
 201         int i;
 202
 203         sprintf(tstring,"%s ", setup_header(t, act));
 204         output(tstring);
 205
 206         buf = (unsigned char *) t + sizeof(*t);
 207         for (i = 0; i < t->pdu_len; i++) {
 208                 sprintf(tstring,"%02x ", buf[i]);
 209                 output(tstring);
 210         }
 211
 212         if (act == 'C') {
 213                 sprintf(tstring,"[%d]", t->error);
 214                 output(tstring);
 215         }
 216
 217         printf("\n");
 218         return 0;
 219 }
 220
 221 static int dump_trace_pc(struct blk_io_trace *t, struct per_file_info *pfi)
 222 {
 223         int ret = 0;
 224
 225         switch (t->action & 0xffff) {
 226                 case __BLK_TA_QUEUE:
 227                         log_generic(t, 'Q');
 228                         break;
 229                 case __BLK_TA_GETRQ:
 230                         log_generic(t, 'G');
 231                         break;
 232                 case __BLK_TA_SLEEPRQ:
 233                         log_generic(t, 'S');
 234                         break;
 235                 case __BLK_TA_REQUEUE:
 236                         log_generic(t, 'R');
 237                         break;
 238                 case __BLK_TA_ISSUE:
 239                         ret = log_pc(t, 'D');
 240                         break;
 241                 case __BLK_TA_COMPLETE:
 242                         log_pc(t, 'C');
 243                         break;
 244                 default:
 245                         fprintf(stderr, "Bad pc action %x\n", t->action);
 246                         ret = 1;
 247                         break;
 248         }
 249
 250         return ret;
 251 }
 252
 253 static void dump_trace_fs(struct blk_io_trace *t, struct per_file_info *pfi)
 254 {
 255         int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
 256
 257         switch (t->action & 0xffff) {
 258                 case __BLK_TA_QUEUE:
 259                         account_q(pfi, w, t->bytes);
 260                         log_queue(t, 'Q');
 261                         break;
 262                 case __BLK_TA_BACKMERGE:
 263                         account_m(pfi, w, t->bytes);
 264                         log_merge(t, 'M');
 265                         break;
 266                 case __BLK_TA_FRONTMERGE:
 267                         account_m(pfi, w, t->bytes);
 268                         log_merge(t, 'F');
 269                         break;
 270                 case __BLK_TA_GETRQ:
 271                         log_generic(t, 'G');
 272                         break;
 273                 case __BLK_TA_SLEEPRQ:
 274                         log_generic(t, 'S');
 275                         break;
 276                 case __BLK_TA_REQUEUE:
 277                         account_c(pfi, w, -t->bytes);
 278                         log_queue(t, 'R');
 279                         break;
 280                 case __BLK_TA_ISSUE:
 281                         account_i(pfi, w, t->bytes);
 282                         log_issue(t, 'D');
 283                         break;
 284                 case __BLK_TA_COMPLETE:
 285                         account_c(pfi, w, t->bytes);
 286                         log_complete(t, 'C');
 287                         break;
 288                 default:
 289                         fprintf(stderr, "Bad fs action %x\n", t->action);
 290                         return;
 291         }
 292 }
 293
 294 static int dump_trace(struct blk_io_trace *t, struct per_file_info *pfi)
 295 {
 296         int ret = 0;
 297
 298         if (t->action & BLK_TC_ACT(BLK_TC_PC))
 299                 ret = dump_trace_pc(t, pfi);
 300         else
 301                 dump_trace_fs(t, pfi);
 302
 303         events++;
 304         return ret;
 305 }
 306
 307 static void dump_pfi_stats(struct per_file_info *pfi)
 308 {
 309         printf("\tReads:\n");
 310         printf("\t\tQueued:    %'8lu, %'8LuKiB\n", pfi->qreads, pfi->qread_kb);
 311         printf("\t\tDispatched %'8lu, %'8LuKiB\n", pfi->ireads, pfi->iread_kb);
 312         printf("\t\tCompleted: %'8lu, %'8LuKiB\n", pfi->creads, pfi->cread_kb);
 313         printf("\t\tMerges:    %'8lu\n", pfi->mreads);
 314
 315         printf("\tWrites:\n");
 316         printf("\t\tQueued:    %'8lu, %'8LuKiB\n", pfi->qwrites,pfi->qwrite_kb);
 317         printf("\t\tDispatched %'8lu, %'8LuKiB\n", pfi->iwrites,pfi->iwrite_kb);
 318         printf("\t\tCompleted: %'8lu, %'8LuKiB\n", pfi->cwrites,pfi->cwrite_kb);
 319         printf("\t\tMerges:    %'8lu\n", pfi->mwrites);
 320 }
 321
 322 static void show_stats(int nfiles)
 323 {
 324         struct per_file_info foo, *pfi;
 325         int i;
 326
 327         memset(&foo, 0, sizeof(foo));
 328
 329         for (i = 0; i < nfiles; i++) {
 330                 pfi = &per_file_info[i];
 331
 332                 if (!pfi->nelems)
 333                         continue;
 334
 335                 foo.qreads += pfi->qreads;
 336                 foo.qwrites += pfi->qwrites;
 337                 foo.creads += pfi->creads;
 338                 foo.cwrites += pfi->cwrites;
 339                 foo.mreads += pfi->mreads;
 340                 foo.mwrites += pfi->mwrites;
 341                 foo.qread_kb += pfi->qread_kb;
 342                 foo.qwrite_kb += pfi->qwrite_kb;
 343                 foo.cread_kb += pfi->cread_kb;
 344                 foo.cwrite_kb += pfi->cwrite_kb;
 345
 346                 printf("CPU%d:\n", i);
 347                 dump_pfi_stats(pfi);
 348         }
 349
 350         if (nfiles > 1) {
 351                 printf("Total:\n");
 352                 dump_pfi_stats(&foo);
 353         }
 354
 355         printf("Events: %'Lu\n", events);
 356 }
 357
 358 static inline int trace_rb_insert(struct trace *t)
 359 {
 360         struct rb_node **p = &rb_root.rb_node;
 361         struct rb_node *parent = NULL;
 362         struct trace *__t;
 363
 364         while (*p) {
 365                 parent = *p;
 366                 __t = rb_entry(parent, struct trace, rb_node);
 367
 368                 if (t->bit->sequence < __t->bit->sequence)
 369                         p = &(*p)->rb_left;
 370                 else if (t->bit->sequence > __t->bit->sequence)
 371                         p = &(*p)->rb_right;
 372                 else {
 373                         fprintf(stderr, "sequence alias!\n");
 374                         return 1;
 375                 }
 376         }
 377
 378         rb_link_node(&t->rb_node, parent, p);
 379         rb_insert_color(&t->rb_node, &rb_root);
 380         return 0;
 381 }
 382
 383 static int sort_entries(void *traces, unsigned long offset, int cpu)
 384 {
 385         struct blk_io_trace *bit;
 386         struct trace *t;
 387         void *start = traces;
 388         int nelems = 0;
 389
 390         while (traces - start <= offset - sizeof(*bit)) {
 391                 bit = traces;
 392
 393                 t = malloc(sizeof(*t));
 394                 t->bit = bit;
 395                 t->cpu = cpu;
 396                 memset(&t->rb_node, 0, sizeof(t->rb_node));
 397
 398                 trace_to_cpu(bit);
 399
 400                 if (verify_trace(bit))
 401                         break;
 402
 403                 if (trace_rb_insert(t))
 404                         return -1;
 405
 406                 traces += sizeof(*bit) + bit->pdu_len;
 407                 nelems++;
 408         }
 409
 410         return nelems;
 411 }
 412
 413 static void show_entries(void)
 414 {
 415         struct blk_io_trace *bit;
 416         struct rb_node *n;
 417         struct trace *t;
 418         int cpu;
 419
 420         n = rb_first(&rb_root);
 421         if (!n)
 422                 return;
 423
 424         do {
 425                 t = rb_entry(n, struct trace, rb_node);
 426                 bit = t->bit;
 427
 428                 cpu = t->cpu;
 429                 if (cpu > max_cpus) {
 430                         fprintf(stderr, "CPU number too large (%d)\n", cpu);
 431                         break;
 432                 }
 433
 434                 cur_file = &per_file_info[cpu];
 435
 436                 if (genesis_time == 0)
 437                         genesis_time = bit->time;
 438                 bit->time -= genesis_time;
 439
 440                 check_time(bit);
 441
 442                 if (dump_trace(bit, cur_file))
 443                         break;
 444
 445         } while ((n = rb_next(n)) != NULL);
 446 }
 447
 448 int main(int argc, char *argv[])
 449 {
 450         int i, nfiles, ret;
 451         char *dev;
 452
 453         if (argc != 2) {
 454                 fprintf(stderr, "Usage: %s <dev>\n", argv[0]);
 455                 return 1;
 456         }
 457
 458         dev = argv[1];
 459
 460         memset(&rb_root, 0, sizeof(rb_root));
 461         memset(per_file_info, 0, sizeof(per_file_info));
 462
 463         for (max_cpus = 0, i = 0, nfiles = 0; i < MAX_CPUS; i++, nfiles++, max_cpus++) {
 464                 struct per_file_info *pfi = &per_file_info[i];
 465                 struct stat st;
 466                 void *tb;
 467
 468                 pfi->cpu = i;
 469
 470                 snprintf(pfi->fname, sizeof(pfi->fname)-1,"%s_out.%d", dev, i);
 471                 if (stat(pfi->fname, &st) < 0)
 472                         break;
 473                 if (!st.st_size)
 474                         continue;
 475
 476                 snprintf(pfi->ofname, sizeof(pfi->ofname)-1, "%s_log.%d", dev, i);
 477                 pfi->ofp = fopen(pfi->ofname, "w");
 478                 if (pfi->ofp == NULL) {
 479                         perror(pfi->ofname);
 480                         break;
 481                 }
 482
 483                 printf("Processing %s\n", pfi->fname);
 484
 485                 tb = malloc(st.st_size);
 486
 487                 pfi->fd = open(pfi->fname, O_RDONLY);
 488                 if (pfi->fd < 0) {
 489                         perror(pfi->fname);
 490                         break;
 491                 }
 492
 493                 if (read(pfi->fd, tb, st.st_size) != st.st_size) {
 494                         fprintf(stderr, "error reading\n");
 495                         break;
 496                 }
 497
 498                 ret = sort_entries(tb, st.st_size, i);
 499                 if (ret == -1)
 500                         break;
 501
 502                 close(pfi->fd);
 503                 pfi->nelems = ret;
 504                 printf("\t%2d %10s %15d\n", i, pfi->fname, pfi->nelems);
 505
 506         }
 507
 508         if (nfiles) {
 509                 show_entries();
 510                 show_stats(nfiles);
 511                 return 0;
 512         }
 513
 514         fprintf(stderr, "No files found\n");
 515         return 1;
 516 }