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