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 #include <getopt.h>
  29 #include <errno.h>
  30 #include <signal.h>
  31 #include <locale.h>
  32 #include <libgen.h>
  33
  34 #include "blktrace.h"
  35 #include "rbtree.h"
  36 #include "jhash.h"
  37
  38 static char blkparse_version[] = "0.99";
  39
  40 struct skip_info {
  41         unsigned long start, end;
  42         struct skip_info *prev, *next;
  43 };
  44
  45 struct per_dev_info {
  46         dev_t dev;
  47         char *name;
  48
  49         int backwards;
  50         unsigned long long events;
  51         unsigned long long first_reported_time;
  52         unsigned long long last_reported_time;
  53         unsigned long long last_read_time;
  54         struct io_stats io_stats;
  55         unsigned long skips, nskips;
  56         unsigned long long seq_skips, seq_nskips;
  57         unsigned int max_depth[2];
  58         unsigned int cur_depth[2];
  59
  60         struct rb_root rb_track;
  61
  62         int nfiles;
  63         int ncpus;
  64
  65         unsigned long *cpu_map;
  66         unsigned int cpu_map_max;
  67
  68         struct per_cpu_info *cpus;
  69 };
  70
  71 struct per_process_info {
  72         char name[16];
  73         __u32 pid;
  74         struct io_stats io_stats;
  75         struct per_process_info *hash_next, *list_next;
  76         int more_than_one;
  77
  78         /*
  79          * individual io stats
  80          */
  81         unsigned long long longest_allocation_wait[2];
  82         unsigned long long longest_dispatch_wait[2];
  83         unsigned long long longest_completion_wait[2];
  84 };
  85
  86 #define PPI_HASH_SHIFT  (8)
  87 #define PPI_HASH_SIZE   (1 << PPI_HASH_SHIFT)
  88 #define PPI_HASH_MASK   (PPI_HASH_SIZE - 1)
  89 static struct per_process_info *ppi_hash_table[PPI_HASH_SIZE];
  90 static struct per_process_info *ppi_list;
  91 static int ppi_list_entries;
  92
  93 #define S_OPTS  "a:A:i:o:b:stqw:f:F:vVhD:"
  94 static struct option l_opts[] = {
  95         {
  96                 .name = "act-mask",
  97                 .has_arg = required_argument,
  98                 .flag = NULL,
  99                 .val = 'a'
 100         },
 101         {
 102                 .name = "set-mask",
 103                 .has_arg = required_argument,
 104                 .flag = NULL,
 105                 .val = 'A'
 106         },
 107         {
 108                 .name = "input",
 109                 .has_arg = required_argument,
 110                 .flag = NULL,
 111                 .val = 'i'
 112         },
 113         {
 114                 .name = "output",
 115                 .has_arg = required_argument,
 116                 .flag = NULL,
 117                 .val = 'o'
 118         },
 119         {
 120                 .name = "batch",
 121                 .has_arg = required_argument,
 122                 .flag = NULL,
 123                 .val = 'b'
 124         },
 125         {
 126                 .name = "per-program-stats",
 127                 .has_arg = no_argument,
 128                 .flag = NULL,
 129                 .val = 's'
 130         },
 131         {
 132                 .name = "track-ios",
 133                 .has_arg = no_argument,
 134                 .flag = NULL,
 135                 .val = 't'
 136         },
 137         {
 138                 .name = "quiet",
 139                 .has_arg = no_argument,
 140                 .flag = NULL,
 141                 .val = 'q'
 142         },
 143         {
 144                 .name = "stopwatch",
 145                 .has_arg = required_argument,
 146                 .flag = NULL,
 147                 .val = 'w'
 148         },
 149         {
 150                 .name = "format",
 151                 .has_arg = required_argument,
 152                 .flag = NULL,
 153                 .val = 'f'
 154         },
 155         {
 156                 .name = "format-spec",
 157                 .has_arg = required_argument,
 158                 .flag = NULL,
 159                 .val = 'F'
 160         },
 161         {
 162                 .name = "hash-by-name",
 163                 .has_arg = no_argument,
 164                 .flag = NULL,
 165                 .val = 'h'
 166         },
 167         {
 168                 .name = "verbose",
 169                 .has_arg = no_argument,
 170                 .flag = NULL,
 171                 .val = 'v'
 172         },
 173         {
 174                 .name = "version",
 175                 .has_arg = no_argument,
 176                 .flag = NULL,
 177                 .val = 'V'
 178         },
 179         {
 180                 .name = "input-directory",
 181                 .has_arg = required_argument,
 182                 .flag = NULL,
 183                 .val = 'D'
 184         },
 185         {
 186                 .name = NULL,
 187         }
 188 };
 189
 190 /*
 191  * for sorting the displayed output
 192  */
 193 struct trace {
 194         struct blk_io_trace *bit;
 195         struct rb_node rb_node;
 196         struct trace *next;
 197         unsigned long read_sequence;
 198 };
 199
 200 static struct rb_root rb_sort_root;
 201 static unsigned long rb_sort_entries;
 202
 203 static struct trace *trace_list;
 204
 205 /*
 206  * allocation cache
 207  */
 208 static struct blk_io_trace *bit_alloc_list;
 209 static struct trace *t_alloc_list;
 210
 211 /*
 212  * for tracking individual ios
 213  */
 214 struct io_track {
 215         struct rb_node rb_node;
 216
 217         __u64 sector;
 218         __u32 pid;
 219         char comm[16];
 220         unsigned long long allocation_time;
 221         unsigned long long queue_time;
 222         unsigned long long dispatch_time;
 223         unsigned long long completion_time;
 224 };
 225
 226 static int ndevices;
 227 static struct per_dev_info *devices;
 228 static char *get_dev_name(struct per_dev_info *, char *, int);
 229 static int trace_rb_insert_last(struct per_dev_info *, struct trace *);
 230
 231 FILE *ofp = NULL;
 232 static char *output_name;
 233 static char *input_dir;
 234
 235 static unsigned long long genesis_time;
 236 static unsigned long long last_allowed_time;
 237 static unsigned long long stopwatch_start;      /* start from zero by default */
 238 static unsigned long long stopwatch_end = -1ULL;        /* "infinity" */
 239 static unsigned long read_sequence;
 240
 241 static int per_process_stats;
 242 static int per_device_and_cpu_stats = 1;
 243 static int track_ios;
 244 static int ppi_hash_by_pid = 1;
 245 static int verbose;
 246 static unsigned int act_mask = -1U;
 247 static int stats_printed;
 248
 249 static unsigned int t_alloc_cache;
 250 static unsigned int bit_alloc_cache;
 251
 252 #define RB_BATCH_DEFAULT        (512)
 253 static unsigned int rb_batch = RB_BATCH_DEFAULT;
 254
 255 static int pipeline;
 256
 257 #define is_done()       (*(volatile int *)(&done))
 258 static volatile int done;
 259
 260 #define JHASH_RANDOM    (0x3af5f2ee)
 261
 262 #define CPUS_PER_LONG   (8 * sizeof(unsigned long))
 263 #define CPU_IDX(cpu)    ((cpu) / CPUS_PER_LONG)
 264 #define CPU_BIT(cpu)    ((cpu) & (CPUS_PER_LONG - 1))
 265
 266 static void resize_cpu_info(struct per_dev_info *pdi, int cpu)
 267 {
 268         struct per_cpu_info *cpus = pdi->cpus;
 269         int ncpus = pdi->ncpus;
 270         int new_count = cpu + 1;
 271         int new_space, size;
 272         char *new_start;
 273
 274         size = new_count * sizeof(struct per_cpu_info);
 275         cpus = realloc(cpus, size);
 276         if (!cpus) {
 277                 char name[20];
 278                 fprintf(stderr, "Out of memory, CPU info for device %s (%d)\n",
 279                         get_dev_name(pdi, name, sizeof(name)), size);
 280                 exit(1);
 281         }
 282
 283         new_start = (char *)cpus + (ncpus * sizeof(struct per_cpu_info));
 284         new_space = (new_count - ncpus) * sizeof(struct per_cpu_info);
 285         memset(new_start, 0, new_space);
 286
 287         pdi->ncpus = new_count;
 288         pdi->cpus = cpus;
 289
 290         for (new_count = 0; new_count < pdi->ncpus; new_count++) {
 291                 struct per_cpu_info *pci = &pdi->cpus[new_count];
 292
 293                 if (!pci->fd) {
 294                         pci->fd = -1;
 295                         memset(&pci->rb_last, 0, sizeof(pci->rb_last));
 296                         pci->rb_last_entries = 0;
 297                         pci->last_sequence = -1;
 298                 }
 299         }
 300 }
 301
 302 static struct per_cpu_info *get_cpu_info(struct per_dev_info *pdi, int cpu)
 303 {
 304         struct per_cpu_info *pci;
 305
 306         if (cpu >= pdi->ncpus)
 307                 resize_cpu_info(pdi, cpu);
 308
 309         pci = &pdi->cpus[cpu];
 310         pci->cpu = cpu;
 311         return pci;
 312 }
 313
 314
 315 static int resize_devices(char *name)
 316 {
 317         int size = (ndevices + 1) * sizeof(struct per_dev_info);
 318
 319         devices = realloc(devices, size);
 320         if (!devices) {
 321                 fprintf(stderr, "Out of memory, device %s (%d)\n", name, size);
 322                 return 1;
 323         }
 324         memset(&devices[ndevices], 0, sizeof(struct per_dev_info));
 325         devices[ndevices].name = name;
 326         ndevices++;
 327         return 0;
 328 }
 329
 330 static struct per_dev_info *get_dev_info(dev_t dev)
 331 {
 332         struct per_dev_info *pdi;
 333         int i;
 334
 335         for (i = 0; i < ndevices; i++) {
 336                 if (!devices[i].dev)
 337                         devices[i].dev = dev;
 338                 if (devices[i].dev == dev)
 339                         return &devices[i];
 340         }
 341
 342         if (resize_devices(NULL))
 343                 return NULL;
 344
 345         pdi = &devices[ndevices - 1];
 346         pdi->dev = dev;
 347         pdi->first_reported_time = 0;
 348         pdi->last_read_time = 0;
 349
 350         return pdi;
 351 }
 352
 353 static void insert_skip(struct per_cpu_info *pci, unsigned long start,
 354                         unsigned long end)
 355 {
 356         struct skip_info *sip;
 357
 358         for (sip = pci->skips_tail; sip != NULL; sip = sip->prev) {
 359                 if (end == (sip->start - 1)) {
 360                         sip->start = start;
 361                         return;
 362                 } else if (start == (sip->end + 1)) {
 363                         sip->end = end;
 364                         return;
 365                 }
 366         }
 367
 368         sip = malloc(sizeof(struct skip_info));
 369         sip->start = start;
 370         sip->end = end;
 371         sip->prev = sip->next = NULL;
 372         if (pci->skips_tail == NULL)
 373                 pci->skips_head = pci->skips_tail = sip;
 374         else {
 375                 sip->prev = pci->skips_tail;
 376                 pci->skips_tail->next = sip;
 377                 pci->skips_tail = sip;
 378         }
 379 }
 380
 381 static void remove_sip(struct per_cpu_info *pci, struct skip_info *sip)
 382 {
 383         if (sip->prev == NULL) {
 384                 if (sip->next == NULL)
 385                         pci->skips_head = pci->skips_tail = NULL;
 386                 else {
 387                         pci->skips_head = sip->next;
 388                         sip->next->prev = NULL;
 389                 }
 390         } else if (sip->next == NULL) {
 391                 pci->skips_tail = sip->prev;
 392                 sip->prev->next = NULL;
 393         } else {
 394                 sip->prev->next = sip->next;
 395                 sip->next->prev = sip->prev;
 396         }
 397
 398         sip->prev = sip->next = NULL;
 399         free(sip);
 400 }
 401
 402 #define IN_SKIP(sip,seq) (((sip)->start <= (seq)) && ((seq) <= sip->end))
 403 static int check_current_skips(struct per_cpu_info *pci, unsigned long seq)
 404 {
 405         struct skip_info *sip;
 406
 407         for (sip = pci->skips_tail; sip != NULL; sip = sip->prev) {
 408                 if (IN_SKIP(sip, seq)) {
 409                         if (sip->start == seq) {
 410                                 if (sip->end == seq)
 411                                         remove_sip(pci, sip);
 412                                 else
 413                                         sip->start += 1;
 414                         } else if (sip->end == seq)
 415                                 sip->end -= 1;
 416                         else {
 417                                 sip->end = seq - 1;
 418                                 insert_skip(pci, seq + 1, sip->end);
 419                         }
 420                         return 1;
 421                 }
 422         }
 423
 424         return 0;
 425 }
 426
 427 static void collect_pdi_skips(struct per_dev_info *pdi)
 428 {
 429         struct skip_info *sip;
 430         int cpu;
 431
 432         pdi->skips = 0;
 433         pdi->seq_skips = 0;
 434
 435         for (cpu = 0; cpu < pdi->ncpus; cpu++) {
 436                 struct per_cpu_info *pci = &pdi->cpus[cpu];
 437
 438                 for (sip = pci->skips_head; sip != NULL; sip = sip->next) {
 439                         pdi->skips++;
 440                         pdi->seq_skips += (sip->end - sip->start + 1);
 441                         if (verbose)
 442                                 fprintf(stderr,"(%d,%d): skipping %lu -> %lu\n",
 443                                         MAJOR(pdi->dev), MINOR(pdi->dev),
 444                                         sip->start, sip->end);
 445                 }
 446         }
 447 }
 448
 449 static void cpu_mark_online(struct per_dev_info *pdi, unsigned int cpu)
 450 {
 451         if (cpu >= pdi->cpu_map_max || !pdi->cpu_map) {
 452                 int new_max = (cpu + CPUS_PER_LONG) & ~(CPUS_PER_LONG - 1);
 453                 unsigned long *map = malloc(new_max / sizeof(long));
 454
 455                 memset(map, 0, new_max / sizeof(long));
 456
 457                 if (pdi->cpu_map) {
 458                         memcpy(map, pdi->cpu_map, pdi->cpu_map_max / sizeof(long));
 459                         free(pdi->cpu_map);
 460                 }
 461
 462                 pdi->cpu_map = map;
 463                 pdi->cpu_map_max = new_max;
 464         }
 465
 466         pdi->cpu_map[CPU_IDX(cpu)] |= (1UL << CPU_BIT(cpu));
 467 }
 468
 469 static inline void cpu_mark_offline(struct per_dev_info *pdi, int cpu)
 470 {
 471         pdi->cpu_map[CPU_IDX(cpu)] &= ~(1UL << CPU_BIT(cpu));
 472 }
 473
 474 static inline int cpu_is_online(struct per_dev_info *pdi, int cpu)
 475 {
 476         return (pdi->cpu_map[CPU_IDX(cpu)] & (1UL << CPU_BIT(cpu))) != 0;
 477 }
 478
 479 static inline int ppi_hash_pid(__u32 pid)
 480 {
 481         return jhash_1word(pid, JHASH_RANDOM) & PPI_HASH_MASK;
 482 }
 483
 484 static inline int ppi_hash_name(const char *name)
 485 {
 486         return jhash(name, 16, JHASH_RANDOM) & PPI_HASH_MASK;
 487 }
 488
 489 static inline int ppi_hash(struct per_process_info *ppi)
 490 {
 491         if (ppi_hash_by_pid)
 492                 return ppi_hash_pid(ppi->pid);
 493
 494         return ppi_hash_name(ppi->name);
 495 }
 496
 497 static inline void add_process_to_hash(struct per_process_info *ppi)
 498 {
 499         const int hash_idx = ppi_hash(ppi);
 500
 501         ppi->hash_next = ppi_hash_table[hash_idx];
 502         ppi_hash_table[hash_idx] = ppi;
 503 }
 504
 505 static inline void add_process_to_list(struct per_process_info *ppi)
 506 {
 507         ppi->list_next = ppi_list;
 508         ppi_list = ppi;
 509         ppi_list_entries++;
 510 }
 511
 512 static struct per_process_info *find_process_by_name(char *name)
 513 {
 514         const int hash_idx = ppi_hash_name(name);
 515         struct per_process_info *ppi;
 516
 517         ppi = ppi_hash_table[hash_idx];
 518         while (ppi) {
 519                 if (!strcmp(ppi->name, name))
 520                         return ppi;
 521
 522                 ppi = ppi->hash_next;
 523         }
 524
 525         return NULL;
 526 }
 527
 528 static struct per_process_info *find_process_by_pid(__u32 pid)
 529 {
 530         const int hash_idx = ppi_hash_pid(pid);
 531         struct per_process_info *ppi;
 532
 533         ppi = ppi_hash_table[hash_idx];
 534         while (ppi) {
 535                 if (ppi->pid == pid)
 536                         return ppi;
 537
 538                 ppi = ppi->hash_next;
 539         }
 540
 541         return NULL;
 542 }
 543
 544 static struct per_process_info *find_process(__u32 pid, char *name)
 545 {
 546         struct per_process_info *ppi;
 547
 548         if (ppi_hash_by_pid)
 549                 return find_process_by_pid(pid);
 550
 551         ppi = find_process_by_name(name);
 552         if (ppi && ppi->pid != pid)
 553                 ppi->more_than_one = 1;
 554
 555         return ppi;
 556 }
 557
 558 /*
 559  * struct trace and blktrace allocation cache, we do potentially
 560  * millions of mallocs for these structures while only using at most
 561  * a few thousand at the time
 562  */
 563 static inline void t_free(struct trace *t)
 564 {
 565         if (t_alloc_cache < 1024) {
 566                 t->next = t_alloc_list;
 567                 t_alloc_list = t;
 568                 t_alloc_cache++;
 569         } else
 570                 free(t);
 571 }
 572
 573 static inline struct trace *t_alloc(void)
 574 {
 575         struct trace *t = t_alloc_list;
 576
 577         if (t) {
 578                 t_alloc_list = t->next;
 579                 t_alloc_cache--;
 580                 return t;
 581         }
 582
 583         return malloc(sizeof(*t));
 584 }
 585
 586 static inline void bit_free(struct blk_io_trace *bit)
 587 {
 588         if (bit_alloc_cache < 1024 && !bit->pdu_len) {
 589                 /*
 590                  * abuse a 64-bit field for a next pointer for the free item
 591                  */
 592                 bit->time = (__u64) (unsigned long) bit_alloc_list;
 593                 bit_alloc_list = (struct blk_io_trace *) bit;
 594                 bit_alloc_cache++;
 595         } else
 596                 free(bit);
 597 }
 598
 599 static inline struct blk_io_trace *bit_alloc(void)
 600 {
 601         struct blk_io_trace *bit = bit_alloc_list;
 602
 603         if (bit) {
 604                 bit_alloc_list = (struct blk_io_trace *) (unsigned long) \
 605                                  bit->time;
 606                 bit_alloc_cache--;
 607                 return bit;
 608         }
 609
 610         return malloc(sizeof(*bit));
 611 }
 612
 613 static inline void __put_trace_last(struct per_dev_info *pdi, struct trace *t)
 614 {
 615         struct per_cpu_info *pci = get_cpu_info(pdi, t->bit->cpu);
 616
 617         rb_erase(&t->rb_node, &pci->rb_last);
 618         pci->rb_last_entries--;
 619
 620         bit_free(t->bit);
 621         t_free(t);
 622 }
 623
 624 static void put_trace(struct per_dev_info *pdi, struct trace *t)
 625 {
 626         rb_erase(&t->rb_node, &rb_sort_root);
 627         rb_sort_entries--;
 628
 629         trace_rb_insert_last(pdi, t);
 630 }
 631
 632 static inline int trace_rb_insert(struct trace *t, struct rb_root *root)
 633 {
 634         struct rb_node **p = &root->rb_node;
 635         struct rb_node *parent = NULL;
 636         struct trace *__t;
 637
 638         while (*p) {
 639                 parent = *p;
 640
 641                 __t = rb_entry(parent, struct trace, rb_node);
 642
 643                 if (t->bit->time < __t->bit->time)
 644                         p = &(*p)->rb_left;
 645                 else if (t->bit->time > __t->bit->time)
 646                         p = &(*p)->rb_right;
 647                 else if (t->bit->device < __t->bit->device)
 648                         p = &(*p)->rb_left;
 649                 else if (t->bit->device > __t->bit->device)
 650                         p = &(*p)->rb_right;
 651                 else if (t->bit->sequence < __t->bit->sequence)
 652                         p = &(*p)->rb_left;
 653                 else    /* >= sequence */
 654                         p = &(*p)->rb_right;
 655         }
 656
 657         rb_link_node(&t->rb_node, parent, p);
 658         rb_insert_color(&t->rb_node, root);
 659         return 0;
 660 }
 661
 662 static inline int trace_rb_insert_sort(struct trace *t)
 663 {
 664         if (!trace_rb_insert(t, &rb_sort_root)) {
 665                 rb_sort_entries++;
 666                 return 0;
 667         }
 668
 669         return 1;
 670 }
 671
 672 static int trace_rb_insert_last(struct per_dev_info *pdi, struct trace *t)
 673 {
 674         struct per_cpu_info *pci = get_cpu_info(pdi, t->bit->cpu);
 675
 676         if (trace_rb_insert(t, &pci->rb_last))
 677                 return 1;
 678
 679         pci->rb_last_entries++;
 680
 681         if (pci->rb_last_entries > rb_batch * pdi->nfiles) {
 682                 struct rb_node *n = rb_first(&pci->rb_last);
 683
 684                 t = rb_entry(n, struct trace, rb_node);
 685                 __put_trace_last(pdi, t);
 686         }
 687
 688         return 0;
 689 }
 690
 691 static struct trace *trace_rb_find(dev_t device, unsigned long sequence,
 692                                    struct rb_root *root, int order)
 693 {
 694         struct rb_node *n = root->rb_node;
 695         struct rb_node *prev = NULL;
 696         struct trace *__t;
 697
 698         while (n) {
 699                 __t = rb_entry(n, struct trace, rb_node);
 700                 prev = n;
 701
 702                 if (device < __t->bit->device)
 703                         n = n->rb_left;
 704                 else if (device > __t->bit->device)
 705                         n = n->rb_right;
 706                 else if (sequence < __t->bit->sequence)
 707                         n = n->rb_left;
 708                 else if (sequence > __t->bit->sequence)
 709                         n = n->rb_right;
 710                 else
 711                         return __t;
 712         }
 713
 714         /*
 715          * hack - the list may not be sequence ordered because some
 716          * events don't have sequence and time matched. so we end up
 717          * being a little off in the rb lookup here, because we don't
 718          * know the time we are looking for. compensate by browsing
 719          * a little ahead from the last entry to find the match
 720          */
 721         if (order && prev) {
 722                 int max = 5;
 723
 724                 while (((n = rb_next(prev)) != NULL) && max--) {
 725                         __t = rb_entry(n, struct trace, rb_node);
 726
 727                         if (__t->bit->device == device &&
 728                             __t->bit->sequence == sequence)
 729                                 return __t;
 730
 731                         prev = n;
 732                 }
 733         }
 734
 735         return NULL;
 736 }
 737
 738 static inline struct trace *trace_rb_find_last(struct per_dev_info *pdi,
 739                                                struct per_cpu_info *pci,
 740                                                unsigned long seq)
 741 {
 742         return trace_rb_find(pdi->dev, seq, &pci->rb_last, 0);
 743 }
 744
 745 static inline int track_rb_insert(struct per_dev_info *pdi,struct io_track *iot)
 746 {
 747         struct rb_node **p = &pdi->rb_track.rb_node;
 748         struct rb_node *parent = NULL;
 749         struct io_track *__iot;
 750
 751         while (*p) {
 752                 parent = *p;
 753                 __iot = rb_entry(parent, struct io_track, rb_node);
 754
 755                 if (iot->sector < __iot->sector)
 756                         p = &(*p)->rb_left;
 757                 else if (iot->sector > __iot->sector)
 758                         p = &(*p)->rb_right;
 759                 else {
 760                         fprintf(stderr,
 761                                 "sector alias (%Lu) on device %d,%d!\n",
 762                                 (unsigned long long) iot->sector,
 763                                 MAJOR(pdi->dev), MINOR(pdi->dev));
 764                         return 1;
 765                 }
 766         }
 767
 768         rb_link_node(&iot->rb_node, parent, p);
 769         rb_insert_color(&iot->rb_node, &pdi->rb_track);
 770         return 0;
 771 }
 772
 773 static struct io_track *__find_track(struct per_dev_info *pdi, __u64 sector)
 774 {
 775         struct rb_node *n = pdi->rb_track.rb_node;
 776         struct io_track *__iot;
 777
 778         while (n) {
 779                 __iot = rb_entry(n, struct io_track, rb_node);
 780
 781                 if (sector < __iot->sector)
 782                         n = n->rb_left;
 783                 else if (sector > __iot->sector)
 784                         n = n->rb_right;
 785                 else
 786                         return __iot;
 787         }
 788
 789         return NULL;
 790 }
 791
 792 static struct io_track *find_track(struct per_dev_info *pdi, __u32 pid,
 793                                    char *comm, __u64 sector)
 794 {
 795         struct io_track *iot;
 796
 797         iot = __find_track(pdi, sector);
 798         if (!iot) {
 799                 iot = malloc(sizeof(*iot));
 800                 iot->pid = pid;
 801                 memcpy(iot->comm, comm, sizeof(iot->comm));
 802                 iot->sector = sector;
 803                 track_rb_insert(pdi, iot);
 804         }
 805
 806         return iot;
 807 }
 808
 809 static void log_track_frontmerge(struct per_dev_info *pdi,
 810                                  struct blk_io_trace *t)
 811 {
 812         struct io_track *iot;
 813
 814         if (!track_ios)
 815                 return;
 816
 817         iot = __find_track(pdi, t->sector + t_sec(t));
 818         if (!iot) {
 819                 if (verbose)
 820                         fprintf(stderr, "merge not found for (%d,%d): %llu\n",
 821                                 MAJOR(pdi->dev), MINOR(pdi->dev),
 822                                 (unsigned long long) t->sector + t_sec(t));
 823                 return;
 824         }
 825
 826         rb_erase(&iot->rb_node, &pdi->rb_track);
 827         iot->sector -= t_sec(t);
 828         track_rb_insert(pdi, iot);
 829 }
 830
 831 static void log_track_getrq(struct per_dev_info *pdi, struct blk_io_trace *t)
 832 {
 833         struct io_track *iot;
 834
 835         if (!track_ios)
 836                 return;
 837
 838         iot = find_track(pdi, t->pid, t->comm, t->sector);
 839         iot->allocation_time = t->time;
 840 }
 841
 842 /*
 843  * return time between rq allocation and insertion
 844  */
 845 static unsigned long long log_track_insert(struct per_dev_info *pdi,
 846                                            struct blk_io_trace *t)
 847 {
 848         unsigned long long elapsed;
 849         struct io_track *iot;
 850
 851         if (!track_ios)
 852                 return -1;
 853
 854         iot = find_track(pdi, t->pid, t->comm, t->sector);
 855         iot->queue_time = t->time;
 856
 857         if (!iot->allocation_time)
 858                 return -1;
 859
 860         elapsed = iot->queue_time - iot->allocation_time;
 861
 862         if (per_process_stats) {
 863                 struct per_process_info *ppi = find_process(iot->pid,iot->comm);
 864                 int w = (t->action & BLK_TC_ACT(BLK_TC_WRITE)) != 0;
 865
 866                 if (ppi && elapsed > ppi->longest_allocation_wait[w])
 867                         ppi->longest_allocation_wait[w] = elapsed;
 868         }
 869
 870         return elapsed;
 871 }
 872
 873 /*
 874  * return time between queue and issue
 875  */
 876 static unsigned long long log_track_issue(struct per_dev_info *pdi,
 877                                           struct blk_io_trace *t)
 878 {
 879         unsigned long long elapsed;
 880         struct io_track *iot;
 881
 882         if (!track_ios)
 883                 return -1;
 884         if ((t->action & BLK_TC_ACT(BLK_TC_FS)) == 0)
 885                 return -1;
 886
 887         iot = __find_track(pdi, t->sector);
 888         if (!iot) {
 889                 if (verbose)
 890                         fprintf(stderr, "issue not found for (%d,%d): %llu\n",
 891                                 MAJOR(pdi->dev), MINOR(pdi->dev),
 892                                 (unsigned long long) t->sector);
 893                 return -1;
 894         }
 895
 896         iot->dispatch_time = t->time;
 897         elapsed = iot->dispatch_time - iot->queue_time;
 898
 899         if (per_process_stats) {
 900                 struct per_process_info *ppi = find_process(iot->pid,iot->comm);
 901                 int w = (t->action & BLK_TC_ACT(BLK_TC_WRITE)) != 0;
 902
 903                 if (ppi && elapsed > ppi->longest_dispatch_wait[w])
 904                         ppi->longest_dispatch_wait[w] = elapsed;
 905         }
 906
 907         return elapsed;
 908 }
 909
 910 /*
 911  * return time between dispatch and complete
 912  */
 913 static unsigned long long log_track_complete(struct per_dev_info *pdi,
 914                                              struct blk_io_trace *t)
 915 {
 916         unsigned long long elapsed;
 917         struct io_track *iot;
 918
 919         if (!track_ios)
 920                 return -1;
 921         if ((t->action & BLK_TC_ACT(BLK_TC_FS)) == 0)
 922                 return -1;
 923
 924         iot = __find_track(pdi, t->sector);
 925         if (!iot) {
 926                 if (verbose)
 927                         fprintf(stderr,"complete not found for (%d,%d): %llu\n",
 928                                 MAJOR(pdi->dev), MINOR(pdi->dev),
 929                                 (unsigned long long) t->sector);
 930                 return -1;
 931         }
 932
 933         iot->completion_time = t->time;
 934         elapsed = iot->completion_time - iot->dispatch_time;
 935
 936         if (per_process_stats) {
 937                 struct per_process_info *ppi = find_process(iot->pid,iot->comm);
 938                 int w = (t->action & BLK_TC_ACT(BLK_TC_WRITE)) != 0;
 939
 940                 if (ppi && elapsed > ppi->longest_completion_wait[w])
 941                         ppi->longest_completion_wait[w] = elapsed;
 942         }
 943
 944         /*
 945          * kill the trace, we don't need it after completion
 946          */
 947         rb_erase(&iot->rb_node, &pdi->rb_track);
 948         free(iot);
 949
 950         return elapsed;
 951 }
 952
 953
 954 static struct io_stats *find_process_io_stats(__u32 pid, char *name)
 955 {
 956         struct per_process_info *ppi = find_process(pid, name);
 957
 958         if (!ppi) {
 959                 ppi = malloc(sizeof(*ppi));
 960                 memset(ppi, 0, sizeof(*ppi));
 961                 memcpy(ppi->name, name, 16);
 962                 ppi->pid = pid;
 963                 add_process_to_hash(ppi);
 964                 add_process_to_list(ppi);
 965         }
 966
 967         return &ppi->io_stats;
 968 }
 969
 970 static char *get_dev_name(struct per_dev_info *pdi, char *buffer, int size)
 971 {
 972         if (pdi->name)
 973                 snprintf(buffer, size, "%s", pdi->name);
 974         else
 975                 snprintf(buffer, size, "%d,%d",MAJOR(pdi->dev),MINOR(pdi->dev));
 976         return buffer;
 977 }
 978
 979 static void check_time(struct per_dev_info *pdi, struct blk_io_trace *bit)
 980 {
 981         unsigned long long this = bit->time;
 982         unsigned long long last = pdi->last_reported_time;
 983
 984         pdi->backwards = (this < last) ? 'B' : ' ';
 985         pdi->last_reported_time = this;
 986 }
 987
 988 static inline void __account_m(struct io_stats *ios, struct blk_io_trace *t,
 989                                int rw)
 990 {
 991         if (rw) {
 992                 ios->mwrites++;
 993                 ios->qwrite_kb += t_kb(t);
 994         } else {
 995                 ios->mreads++;
 996                 ios->qread_kb += t_kb(t);
 997         }
 998 }
 999
1000 static inline void account_m(struct blk_io_trace *t, struct per_cpu_info *pci,
1001                              int rw)
1002 {
1003         __account_m(&pci->io_stats, t, rw);
1004
1005         if (per_process_stats) {
1006                 struct io_stats *ios = find_process_io_stats(t->pid, t->comm);
1007
1008                 __account_m(ios, t, rw);
1009         }
1010 }
1011
1012 static inline void __account_queue(struct io_stats *ios, struct blk_io_trace *t,
1013                                    int rw)
1014 {
1015         if (rw) {
1016                 ios->qwrites++;
1017                 ios->qwrite_kb += t_kb(t);
1018         } else {
1019                 ios->qreads++;
1020                 ios->qread_kb += t_kb(t);
1021         }
1022 }
1023
1024 static inline void account_queue(struct blk_io_trace *t,
1025                                  struct per_cpu_info *pci, int rw)
1026 {
1027         __account_queue(&pci->io_stats, t, rw);
1028
1029         if (per_process_stats) {
1030                 struct io_stats *ios = find_process_io_stats(t->pid, t->comm);
1031
1032                 __account_queue(ios, t, rw);
1033         }
1034 }
1035
1036 static inline void __account_c(struct io_stats *ios, int rw, int bytes)
1037 {
1038         if (rw) {
1039                 ios->cwrites++;
1040                 ios->cwrite_kb += bytes >> 10;
1041         } else {
1042                 ios->creads++;
1043                 ios->cread_kb += bytes >> 10;
1044         }
1045 }
1046
1047 static inline void account_c(struct blk_io_trace *t, struct per_cpu_info *pci,
1048                              int rw, int bytes)
1049 {
1050         __account_c(&pci->io_stats, rw, bytes);
1051
1052         if (per_process_stats) {
1053                 struct io_stats *ios = find_process_io_stats(t->pid, t->comm);
1054
1055                 __account_c(ios, rw, bytes);
1056         }
1057 }
1058
1059 static inline void __account_issue(struct io_stats *ios, int rw,
1060                                    unsigned int bytes)
1061 {
1062         if (rw) {
1063                 ios->iwrites++;
1064                 ios->iwrite_kb += bytes >> 10;
1065         } else {
1066                 ios->ireads++;
1067                 ios->iread_kb += bytes >> 10;
1068         }
1069 }
1070
1071 static inline void account_issue(struct blk_io_trace *t,
1072                                  struct per_cpu_info *pci, int rw)
1073 {
1074         __account_issue(&pci->io_stats, rw, t->bytes);
1075
1076         if (per_process_stats) {
1077                 struct io_stats *ios = find_process_io_stats(t->pid, t->comm);
1078
1079                 __account_issue(ios, rw, t->bytes);
1080         }
1081 }
1082
1083 static inline void __account_unplug(struct io_stats *ios, int timer)
1084 {
1085         if (timer)
1086                 ios->timer_unplugs++;
1087         else
1088                 ios->io_unplugs++;
1089 }
1090
1091 static inline void account_unplug(struct blk_io_trace *t,
1092                                   struct per_cpu_info *pci, int timer)
1093 {
1094         __account_unplug(&pci->io_stats, timer);
1095
1096         if (per_process_stats) {
1097                 struct io_stats *ios = find_process_io_stats(t->pid, t->comm);
1098
1099                 __account_unplug(ios, timer);
1100         }
1101 }
1102
1103 static inline void __account_requeue(struct io_stats *ios,
1104                                      struct blk_io_trace *t, int rw)
1105 {
1106         if (rw) {
1107                 ios->wrqueue++;
1108                 ios->iwrite_kb -= t_kb(t);
1109         } else {
1110                 ios->rrqueue++;
1111                 ios->iread_kb -= t_kb(t);
1112         }
1113 }
1114
1115 static inline void account_requeue(struct blk_io_trace *t,
1116                                    struct per_cpu_info *pci, int rw)
1117 {
1118         __account_requeue(&pci->io_stats, t, rw);
1119
1120         if (per_process_stats) {
1121                 struct io_stats *ios = find_process_io_stats(t->pid, t->comm);
1122
1123                 __account_requeue(ios, t, rw);
1124         }
1125 }
1126
1127 static void log_complete(struct per_dev_info *pdi, struct per_cpu_info *pci,
1128                          struct blk_io_trace *t, char *act)
1129 {
1130         process_fmt(act, pci, t, log_track_complete(pdi, t), 0, NULL);
1131 }
1132
1133 static void log_insert(struct per_dev_info *pdi, struct per_cpu_info *pci,
1134                        struct blk_io_trace *t, char *act)
1135 {
1136         process_fmt(act, pci, t, log_track_insert(pdi, t), 0, NULL);
1137 }
1138
1139 static void log_queue(struct per_cpu_info *pci, struct blk_io_trace *t,
1140                       char *act)
1141 {
1142         process_fmt(act, pci, t, -1, 0, NULL);
1143 }
1144
1145 static void log_issue(struct per_dev_info *pdi, struct per_cpu_info *pci,
1146                       struct blk_io_trace *t, char *act)
1147 {
1148         process_fmt(act, pci, t, log_track_issue(pdi, t), 0, NULL);
1149 }
1150
1151 static void log_merge(struct per_dev_info *pdi, struct per_cpu_info *pci,
1152                       struct blk_io_trace *t, char *act)
1153 {
1154         if (act[0] == 'F')
1155                 log_track_frontmerge(pdi, t);
1156
1157         process_fmt(act, pci, t, -1ULL, 0, NULL);
1158 }
1159
1160 static void log_action(struct per_cpu_info *pci, struct blk_io_trace *t,
1161                         char *act)
1162 {
1163         process_fmt(act, pci, t, -1ULL, 0, NULL);
1164 }
1165
1166 static void log_generic(struct per_cpu_info *pci, struct blk_io_trace *t,
1167                         char *act)
1168 {
1169         process_fmt(act, pci, t, -1ULL, 0, NULL);
1170 }
1171
1172 static void log_unplug(struct per_cpu_info *pci, struct blk_io_trace *t,
1173                       char *act)
1174 {
1175         process_fmt(act, pci, t, -1ULL, 0, NULL);
1176 }
1177
1178 static void log_split(struct per_cpu_info *pci, struct blk_io_trace *t,
1179                       char *act)
1180 {
1181         process_fmt(act, pci, t, -1ULL, 0, NULL);
1182 }
1183
1184 static void log_pc(struct per_cpu_info *pci, struct blk_io_trace *t, char *act)
1185 {
1186         unsigned char *buf = (unsigned char *) t + sizeof(*t);
1187
1188         process_fmt(act, pci, t, -1ULL, t->pdu_len, buf);
1189 }
1190
1191 static void dump_trace_pc(struct blk_io_trace *t, struct per_cpu_info *pci)
1192 {
1193         int act = t->action & 0xffff;
1194
1195         switch (act) {
1196                 case __BLK_TA_QUEUE:
1197                         log_generic(pci, t, "Q");
1198                         break;
1199                 case __BLK_TA_GETRQ:
1200                         log_generic(pci, t, "G");
1201                         break;
1202                 case __BLK_TA_SLEEPRQ:
1203                         log_generic(pci, t, "S");
1204                         break;
1205                 case __BLK_TA_REQUEUE:
1206                         log_generic(pci, t, "R");
1207                         break;
1208                 case __BLK_TA_ISSUE:
1209                         log_pc(pci, t, "D");
1210                         break;
1211                 case __BLK_TA_COMPLETE:
1212                         log_pc(pci, t, "C");
1213                         break;
1214                 case __BLK_TA_INSERT:
1215                         log_pc(pci, t, "I");
1216                         break;
1217                 default:
1218                         fprintf(stderr, "Bad pc action %x\n", act);
1219                         break;
1220         }
1221 }
1222
1223 static void dump_trace_fs(struct blk_io_trace *t, struct per_dev_info *pdi,
1224                           struct per_cpu_info *pci)
1225 {
1226         int w = (t->action & BLK_TC_ACT(BLK_TC_WRITE)) != 0;
1227         int act = t->action & 0xffff;
1228
1229         switch (act) {
1230                 case __BLK_TA_QUEUE:
1231                         account_queue(t, pci, w);
1232                         log_queue(pci, t, "Q");
1233                         break;
1234                 case __BLK_TA_INSERT:
1235                         log_insert(pdi, pci, t, "I");
1236                         break;
1237                 case __BLK_TA_BACKMERGE:
1238                         account_m(t, pci, w);
1239                         log_merge(pdi, pci, t, "M");
1240                         break;
1241                 case __BLK_TA_FRONTMERGE:
1242                         account_m(t, pci, w);
1243                         log_merge(pdi, pci, t, "F");
1244                         break;
1245                 case __BLK_TA_GETRQ:
1246                         log_track_getrq(pdi, t);
1247                         log_generic(pci, t, "G");
1248                         break;
1249                 case __BLK_TA_SLEEPRQ:
1250                         log_generic(pci, t, "S");
1251                         break;
1252                 case __BLK_TA_REQUEUE:
1253                         pdi->cur_depth[w]--;
1254                         account_requeue(t, pci, w);
1255                         log_queue(pci, t, "R");
1256                         break;
1257                 case __BLK_TA_ISSUE:
1258                         account_issue(t, pci, w);
1259                         pdi->cur_depth[w]++;
1260                         if (pdi->cur_depth[w] > pdi->max_depth[w])
1261                                 pdi->max_depth[w] = pdi->cur_depth[w];
1262                         log_issue(pdi, pci, t, "D");
1263                         break;
1264                 case __BLK_TA_COMPLETE:
1265                         pdi->cur_depth[w]--;
1266                         account_c(t, pci, w, t->bytes);
1267                         log_complete(pdi, pci, t, "C");
1268                         break;
1269                 case __BLK_TA_PLUG:
1270                         log_action(pci, t, "P");
1271                         break;
1272                 case __BLK_TA_UNPLUG_IO:
1273                         account_unplug(t, pci, 0);
1274                         log_unplug(pci, t, "U");
1275                         break;
1276                 case __BLK_TA_UNPLUG_TIMER:
1277                         account_unplug(t, pci, 1);
1278                         log_unplug(pci, t, "UT");
1279                         break;
1280                 case __BLK_TA_SPLIT:
1281                         log_split(pci, t, "X");
1282                         break;
1283                 case __BLK_TA_BOUNCE:
1284                         log_generic(pci, t, "B");
1285                         break;
1286                 case __BLK_TA_REMAP:
1287                         log_generic(pci, t, "A");
1288                         break;
1289                 default:
1290                         fprintf(stderr, "Bad fs action %x\n", t->action);
1291                         break;
1292         }
1293 }
1294
1295 static void dump_trace(struct blk_io_trace *t, struct per_cpu_info *pci,
1296                        struct per_dev_info *pdi)
1297 {
1298         if (t->action & BLK_TC_ACT(BLK_TC_PC))
1299                 dump_trace_pc(t, pci);
1300         else
1301                 dump_trace_fs(t, pdi, pci);
1302
1303         if (!pdi->events)
1304                 pdi->first_reported_time = t->time;
1305
1306         pdi->events++;
1307 }
1308
1309 /*
1310  * print in a proper way, not too small and not too big. if more than
1311  * 1000,000K, turn into M and so on
1312  */
1313 static char *size_cnv(char *dst, unsigned long long num, int in_kb)
1314 {
1315         char suff[] = { '\0', 'K', 'M', 'G', 'P' };
1316         unsigned int i = 0;
1317
1318         if (in_kb)
1319                 i++;
1320
1321         while (num > 1000 * 1000ULL && (i < sizeof(suff) - 1)) {
1322                 i++;
1323                 num /= 1000;
1324         }
1325
1326         sprintf(dst, "%'8Lu%c", num, suff[i]);
1327         return dst;
1328 }
1329
1330 static void dump_io_stats(struct per_dev_info *pdi, struct io_stats *ios,
1331                           char *msg)
1332 {
1333         static char x[256], y[256];
1334
1335         fprintf(ofp, "%s\n", msg);
1336
1337         fprintf(ofp, " Reads Queued:    %s, %siB\t", size_cnv(x, ios->qreads, 0), size_cnv(y, ios->qread_kb, 1));
1338         fprintf(ofp, " Writes Queued:    %s, %siB\n", size_cnv(x, ios->qwrites, 0), size_cnv(y, ios->qwrite_kb, 1));
1339
1340         fprintf(ofp, " Read Dispatches: %s, %siB\t", size_cnv(x, ios->ireads, 0), size_cnv(y, ios->iread_kb, 1));
1341         fprintf(ofp, " Write Dispatches: %s, %siB\n", size_cnv(x, ios->iwrites, 0), size_cnv(y, ios->iwrite_kb, 1));
1342         fprintf(ofp, " Reads Requeued:  %s\t\t", size_cnv(x, ios->rrqueue, 0));
1343         fprintf(ofp, " Writes Requeued:  %s\n", size_cnv(x, ios->wrqueue, 0));
1344         fprintf(ofp, " Reads Completed: %s, %siB\t", size_cnv(x, ios->creads, 0), size_cnv(y, ios->cread_kb, 1));
1345         fprintf(ofp, " Writes Completed: %s, %siB\n", size_cnv(x, ios->cwrites, 0), size_cnv(y, ios->cwrite_kb, 1));
1346         fprintf(ofp, " Read Merges:     %'8lu%8c\t", ios->mreads, ' ');
1347         fprintf(ofp, " Write Merges:     %'8lu\n", ios->mwrites);
1348         if (pdi) {
1349                 fprintf(ofp, " Read depth:      %'8u%8c\t", pdi->max_depth[0], ' ');
1350                 fprintf(ofp, " Write depth:      %'8u\n", pdi->max_depth[1]);
1351         }
1352         fprintf(ofp, " IO unplugs:      %'8lu%8c\t", ios->io_unplugs, ' ');
1353         fprintf(ofp, " Timer unplugs:    %'8lu\n", ios->timer_unplugs);
1354 }
1355
1356 static void dump_wait_stats(struct per_process_info *ppi)
1357 {
1358         unsigned long rawait = ppi->longest_allocation_wait[0] / 1000;
1359         unsigned long rdwait = ppi->longest_dispatch_wait[0] / 1000;
1360         unsigned long rcwait = ppi->longest_completion_wait[0] / 1000;
1361         unsigned long wawait = ppi->longest_allocation_wait[1] / 1000;
1362         unsigned long wdwait = ppi->longest_dispatch_wait[1] / 1000;
1363         unsigned long wcwait = ppi->longest_completion_wait[1] / 1000;
1364
1365         fprintf(ofp, " Allocation wait: %'8lu%8c\t", rawait, ' ');
1366         fprintf(ofp, " Allocation wait:  %'8lu\n", wawait);
1367         fprintf(ofp, " Dispatch wait:   %'8lu%8c\t", rdwait, ' ');
1368         fprintf(ofp, " Dispatch wait:    %'8lu\n", wdwait);
1369         fprintf(ofp, " Completion wait: %'8lu%8c\t", rcwait, ' ');
1370         fprintf(ofp, " Completion wait:  %'8lu\n", wcwait);
1371 }
1372
1373 static int ppi_name_compare(const void *p1, const void *p2)
1374 {
1375         struct per_process_info *ppi1 = *((struct per_process_info **) p1);
1376         struct per_process_info *ppi2 = *((struct per_process_info **) p2);
1377         int res;
1378
1379         res = strverscmp(ppi1->name, ppi2->name);
1380         if (!res)
1381                 res = ppi1->pid > ppi2->pid;
1382
1383         return res;
1384 }
1385
1386 static void sort_process_list(void)
1387 {
1388         struct per_process_info **ppis;
1389         struct per_process_info *ppi;
1390         int i = 0;
1391
1392         ppis = malloc(ppi_list_entries * sizeof(struct per_process_info *));
1393
1394         ppi = ppi_list;
1395         while (ppi) {
1396                 ppis[i++] = ppi;
1397                 ppi = ppi->list_next;
1398         }
1399
1400         qsort(ppis, ppi_list_entries, sizeof(ppi), ppi_name_compare);
1401
1402         i = ppi_list_entries - 1;
1403         ppi_list = NULL;
1404         while (i >= 0) {
1405                 ppi = ppis[i];
1406
1407                 ppi->list_next = ppi_list;
1408                 ppi_list = ppi;
1409                 i--;
1410         }
1411
1412         free(ppis);
1413 }
1414
1415 static void show_process_stats(void)
1416 {
1417         struct per_process_info *ppi;
1418
1419         sort_process_list();
1420
1421         ppi = ppi_list;
1422         while (ppi) {
1423                 char name[64];
1424
1425                 if (ppi->more_than_one)
1426                         sprintf(name, "%s (%u, ...)", ppi->name, ppi->pid);
1427                 else
1428                         sprintf(name, "%s (%u)", ppi->name, ppi->pid);
1429
1430                 dump_io_stats(NULL, &ppi->io_stats, name);
1431                 dump_wait_stats(ppi);
1432                 ppi = ppi->list_next;
1433         }
1434
1435         fprintf(ofp, "\n");
1436 }
1437
1438 static void show_device_and_cpu_stats(void)
1439 {
1440         struct per_dev_info *pdi;
1441         struct per_cpu_info *pci;
1442         struct io_stats total, *ios;
1443         unsigned long long rrate, wrate, msec;
1444         int i, j, pci_events;
1445         char line[3 + 8/*cpu*/ + 2 + 32/*dev*/ + 3];
1446         char name[32];
1447
1448         for (pdi = devices, i = 0; i < ndevices; i++, pdi++) {
1449
1450                 memset(&total, 0, sizeof(total));
1451                 pci_events = 0;
1452
1453                 if (i > 0)
1454                         fprintf(ofp, "\n");
1455
1456                 for (pci = pdi->cpus, j = 0; j < pdi->ncpus; j++, pci++) {
1457                         if (!pci->nelems)
1458                                 continue;
1459
1460                         ios = &pci->io_stats;
1461                         total.qreads += ios->qreads;
1462                         total.qwrites += ios->qwrites;
1463                         total.creads += ios->creads;
1464                         total.cwrites += ios->cwrites;
1465                         total.mreads += ios->mreads;
1466                         total.mwrites += ios->mwrites;
1467                         total.ireads += ios->ireads;
1468                         total.iwrites += ios->iwrites;
1469                         total.rrqueue += ios->rrqueue;
1470                         total.wrqueue += ios->wrqueue;
1471                         total.qread_kb += ios->qread_kb;
1472                         total.qwrite_kb += ios->qwrite_kb;
1473                         total.cread_kb += ios->cread_kb;
1474                         total.cwrite_kb += ios->cwrite_kb;
1475                         total.iread_kb += ios->iread_kb;
1476                         total.iwrite_kb += ios->iwrite_kb;
1477                         total.timer_unplugs += ios->timer_unplugs;
1478                         total.io_unplugs += ios->io_unplugs;
1479
1480                         snprintf(line, sizeof(line) - 1, "CPU%d (%s):",
1481                                  j, get_dev_name(pdi, name, sizeof(name)));
1482                         dump_io_stats(pdi, ios, line);
1483                         pci_events++;
1484                 }
1485
1486                 if (pci_events > 1) {
1487                         fprintf(ofp, "\n");
1488                         snprintf(line, sizeof(line) - 1, "Total (%s):",
1489                                  get_dev_name(pdi, name, sizeof(name)));
1490                         dump_io_stats(NULL, &total, line);
1491                 }
1492
1493                 wrate = rrate = 0;
1494                 msec = (pdi->last_reported_time - pdi->first_reported_time) / 1000000;
1495                 if (msec) {
1496                         rrate = 1000 * total.cread_kb / msec;
1497                         wrate = 1000 * total.cwrite_kb / msec;
1498                 }
1499
1500                 fprintf(ofp, "\nThroughput (R/W): %'LuKiB/s / %'LuKiB/s\n",
1501                         rrate, wrate);
1502                 fprintf(ofp, "Events (%s): %'Lu entries\n",
1503                         get_dev_name(pdi, line, sizeof(line)), pdi->events);
1504
1505                 collect_pdi_skips(pdi);
1506                 fprintf(ofp, "Skips: %'lu forward (%'llu - %5.1lf%%)\n",
1507                         pdi->skips,pdi->seq_skips,
1508                         100.0 * ((double)pdi->seq_skips /
1509                                 (double)(pdi->events + pdi->seq_skips)));
1510         }
1511 }
1512
1513 static void find_genesis(void)
1514 {
1515         struct trace *t = trace_list;
1516
1517         genesis_time = -1ULL;
1518         while (t != NULL) {
1519                 if (t->bit->time < genesis_time)
1520                         genesis_time = t->bit->time;
1521
1522                 t = t->next;
1523         }
1524 }
1525
1526 static inline int check_stopwatch(struct blk_io_trace *bit)
1527 {
1528         if (bit->time < stopwatch_end &&
1529             bit->time >= stopwatch_start)
1530                 return 0;
1531
1532         return 1;
1533 }
1534
1535 /*
1536  * return youngest entry read
1537  */
1538 static int sort_entries(unsigned long long *youngest)
1539 {
1540         struct per_dev_info *pdi = NULL;
1541         struct per_cpu_info *pci = NULL;
1542         struct trace *t;
1543
1544         if (!genesis_time)
1545                 find_genesis();
1546
1547         *youngest = 0;
1548         while ((t = trace_list) != NULL) {
1549                 struct blk_io_trace *bit = t->bit;
1550
1551                 trace_list = t->next;
1552
1553                 bit->time -= genesis_time;
1554
1555                 if (bit->time < *youngest || !*youngest)
1556                         *youngest = bit->time;
1557
1558                 if (!pdi || pdi->dev != bit->device) {
1559                         pdi = get_dev_info(bit->device);
1560                         pci = NULL;
1561                 }
1562
1563                 if (!pci || pci->cpu != bit->cpu)
1564                         pci = get_cpu_info(pdi, bit->cpu);
1565
1566                 if (bit->sequence < pci->smallest_seq_read)
1567                         pci->smallest_seq_read = bit->sequence;
1568
1569                 if (check_stopwatch(bit)) {
1570                         bit_free(bit);
1571                         t_free(t);
1572                         continue;
1573                 }
1574
1575                 if (trace_rb_insert_sort(t))
1576                         return -1;
1577         }
1578
1579         return 0;
1580 }
1581
1582 /*
1583  * to continue, we must have traces from all online cpus in the tree
1584  */
1585 static int check_cpu_map(struct per_dev_info *pdi)
1586 {
1587         unsigned long *cpu_map;
1588         struct rb_node *n;
1589         struct trace *__t;
1590         unsigned int i;
1591         int ret, cpu;
1592
1593         /*
1594          * create a map of the cpus we have traces for
1595          */
1596         cpu_map = malloc(pdi->cpu_map_max / sizeof(long));
1597         n = rb_first(&rb_sort_root);
1598         while (n) {
1599                 __t = rb_entry(n, struct trace, rb_node);
1600                 cpu = __t->bit->cpu;
1601
1602                 cpu_map[CPU_IDX(cpu)] |= (1UL << CPU_BIT(cpu));
1603                 n = rb_next(n);
1604         }
1605
1606         /*
1607          * we can't continue if pdi->cpu_map has entries set that we don't
1608          * have in the sort rbtree. the opposite is not a problem, though
1609          */
1610         ret = 0;
1611         for (i = 0; i < pdi->cpu_map_max / CPUS_PER_LONG; i++) {
1612                 if (pdi->cpu_map[i] & ~(cpu_map[i])) {
1613                         ret = 1;
1614                         break;
1615                 }
1616         }
1617
1618         free(cpu_map);
1619         return ret;
1620 }
1621
1622 static int check_sequence(struct per_dev_info *pdi, struct trace *t, int force)
1623 {
1624         struct blk_io_trace *bit = t->bit;
1625         unsigned long expected_sequence;
1626         struct per_cpu_info *pci;
1627         struct trace *__t;
1628
1629         pci = get_cpu_info(pdi, bit->cpu);
1630         expected_sequence = pci->last_sequence + 1;
1631
1632         if (!expected_sequence) {
1633                 /*
1634                  * 1 should be the first entry, just allow it
1635                  */
1636                 if (bit->sequence == 1)
1637                         return 0;
1638                 if (bit->sequence == pci->smallest_seq_read)
1639                         return 0;
1640
1641                 return check_cpu_map(pdi);
1642         }
1643
1644         if (bit->sequence == expected_sequence)
1645                 return 0;
1646
1647         /*
1648          * we may not have seen that sequence yet. if we are not doing
1649          * the final run, break and wait for more entries.
1650          */
1651         if (expected_sequence < pci->smallest_seq_read) {
1652                 __t = trace_rb_find_last(pdi, pci, expected_sequence);
1653                 if (!__t)
1654                         goto skip;
1655
1656                 __put_trace_last(pdi, __t);
1657                 return 0;
1658         } else if (!force) {
1659                 return 1;
1660         } else {
1661 skip:
1662                 if (check_current_skips(pci, bit->sequence))
1663                         return 0;
1664
1665                 if (expected_sequence < bit->sequence)
1666                         insert_skip(pci, expected_sequence, bit->sequence - 1);
1667                 return 0;
1668         }
1669 }
1670
1671 static void show_entries_rb(int force)
1672 {
1673         struct per_dev_info *pdi = NULL;
1674         struct per_cpu_info *pci = NULL;
1675         struct blk_io_trace *bit;
1676         struct rb_node *n;
1677         struct trace *t;
1678
1679         while ((n = rb_first(&rb_sort_root)) != NULL) {
1680                 if (is_done() && !force && !pipeline)
1681                         break;
1682
1683                 t = rb_entry(n, struct trace, rb_node);
1684                 bit = t->bit;
1685
1686                 if (read_sequence - t->read_sequence < 1 && !force)
1687                         break;
1688
1689                 if (!pdi || pdi->dev != bit->device) {
1690                         pdi = get_dev_info(bit->device);
1691                         pci = NULL;
1692                 }
1693
1694                 if (!pdi) {
1695                         fprintf(stderr, "Unknown device ID? (%d,%d)\n",
1696                                 MAJOR(bit->device), MINOR(bit->device));
1697                         break;
1698                 }
1699
1700                 if (check_sequence(pdi, t, force))
1701                         break;
1702
1703                 if (!force && bit->time > last_allowed_time)
1704                         break;
1705
1706                 check_time(pdi, bit);
1707
1708                 if (!pci || pci->cpu != bit->cpu)
1709                         pci = get_cpu_info(pdi, bit->cpu);
1710
1711                 pci->last_sequence = bit->sequence;
1712
1713                 pci->nelems++;
1714
1715                 if (bit->action & (act_mask << BLK_TC_SHIFT))
1716                         dump_trace(bit, pci, pdi);
1717
1718                 put_trace(pdi, t);
1719         }
1720 }
1721
1722 static int read_data(int fd, void *buffer, int bytes, int block, int *fdblock)
1723 {
1724         int ret, bytes_left, fl;
1725         void *p;
1726
1727         if (block != *fdblock) {
1728                 fl = fcntl(fd, F_GETFL);
1729
1730                 if (!block) {
1731                         *fdblock = 0;
1732                         fcntl(fd, F_SETFL, fl | O_NONBLOCK);
1733                 } else {
1734                         *fdblock = 1;
1735                         fcntl(fd, F_SETFL, fl & ~O_NONBLOCK);
1736                 }
1737         }
1738
1739         bytes_left = bytes;
1740         p = buffer;
1741         while (bytes_left > 0) {
1742                 ret = read(fd, p, bytes_left);
1743                 if (!ret)
1744                         return 1;
1745                 else if (ret < 0) {
1746                         if (errno != EAGAIN) {
1747                                 perror("read");
1748                                 return -1;
1749                         }
1750
1751                         /*
1752                          * never do partial reads. we can return if we
1753                          * didn't read anything and we should not block,
1754                          * otherwise wait for data
1755                          */
1756                         if ((bytes_left == bytes) && !block)
1757                                 return 1;
1758
1759                         usleep(10);
1760                         continue;
1761                 } else {
1762                         p += ret;
1763                         bytes_left -= ret;
1764                 }
1765         }
1766
1767         return 0;
1768 }
1769
1770 static int read_events(int fd, int always_block, int *fdblock)
1771 {
1772         struct per_dev_info *pdi = NULL;
1773         unsigned int events = 0;
1774
1775         while (!is_done() && events < rb_batch) {
1776                 struct blk_io_trace *bit;
1777                 struct trace *t;
1778                 int pdu_len, should_block, ret;
1779                 __u32 magic;
1780
1781                 bit = bit_alloc();
1782
1783                 should_block = !events || always_block;
1784
1785                 ret = read_data(fd, bit, sizeof(*bit), should_block, fdblock);
1786                 if (ret) {
1787                         bit_free(bit);
1788                         if (!events && ret < 0)
1789                                 events = ret;
1790                         break;
1791                 }
1792
1793                 magic = be32_to_cpu(bit->magic);
1794                 if ((magic & 0xffffff00) != BLK_IO_TRACE_MAGIC) {
1795                         fprintf(stderr, "Bad magic %x\n", magic);
1796                         break;
1797                 }
1798
1799                 pdu_len = be16_to_cpu(bit->pdu_len);
1800                 if (pdu_len) {
1801                         void *ptr = realloc(bit, sizeof(*bit) + pdu_len);
1802
1803                         if (read_data(fd, ptr + sizeof(*bit), pdu_len, 1, fdblock)) {
1804                                 bit_free(ptr);
1805                                 break;
1806                         }
1807
1808                         bit = ptr;
1809                 }
1810
1811                 trace_to_cpu(bit);
1812
1813                 if (verify_trace(bit)) {
1814                         bit_free(bit);
1815                         continue;
1816                 }
1817
1818                 t = t_alloc();
1819                 memset(t, 0, sizeof(*t));
1820                 t->bit = bit;
1821                 t->read_sequence = read_sequence;
1822
1823                 t->next = trace_list;
1824                 trace_list = t;
1825
1826                 if (!pdi || pdi->dev != bit->device)
1827                         pdi = get_dev_info(bit->device);
1828
1829                 if (bit->time > pdi->last_read_time)
1830                         pdi->last_read_time = bit->time;
1831
1832                 events++;
1833         }
1834
1835         return events;
1836 }
1837
1838 static int do_file(void)
1839 {
1840         struct per_cpu_info *pci;
1841         struct per_dev_info *pdi;
1842         int i, j, events, events_added;
1843
1844         /*
1845          * first prepare all files for reading
1846          */
1847         for (i = 0; i < ndevices; i++) {
1848                 pdi = &devices[i];
1849                 pdi->nfiles = 0;
1850
1851                 for (j = 0;; j++) {
1852                         struct stat st;
1853                         int len = 0;
1854                         char *p, *dname;
1855
1856                         pci = get_cpu_info(pdi, j);
1857                         pci->cpu = j;
1858                         pci->fd = -1;
1859                         pci->fdblock = -1;
1860
1861                         p = strdup(pdi->name);
1862                         dname = dirname(p);
1863                         if (strcmp(dname, ".")) {
1864                                 input_dir = dname;
1865                                 p = strdup(pdi->name);
1866                                 strcpy(pdi->name, basename(p));
1867                         }
1868                         free(p);
1869
1870                         if (input_dir)
1871                                 len = sprintf(pci->fname, "%s/", input_dir);
1872
1873                         snprintf(pci->fname + len, sizeof(pci->fname)-1-len,
1874                                  "%s.blktrace.%d", pdi->name, pci->cpu);
1875                         if (stat(pci->fname, &st) < 0)
1876                                 break;
1877                         if (st.st_size) {
1878                                 pci->fd = open(pci->fname, O_RDONLY);
1879                                 if (pci->fd < 0) {
1880                                         perror(pci->fname);
1881                                         continue;
1882                                 }
1883                         }
1884
1885                         printf("Input file %s added\n", pci->fname);
1886                         pdi->nfiles++;
1887                         cpu_mark_online(pdi, pci->cpu);
1888                 }
1889         }
1890
1891         /*
1892          * now loop over the files reading in the data
1893          */
1894         do {
1895                 unsigned long long youngest;
1896
1897                 events_added = 0;
1898                 last_allowed_time = -1ULL;
1899                 read_sequence++;
1900
1901                 for (i = 0; i < ndevices; i++) {
1902                         pdi = &devices[i];
1903                         pdi->last_read_time = -1ULL;
1904
1905                         for (j = 0; j < pdi->nfiles; j++) {
1906
1907                                 pci = get_cpu_info(pdi, j);
1908
1909                                 if (pci->fd == -1)
1910                                         continue;
1911
1912                                 pci->smallest_seq_read = -1;
1913
1914                                 events = read_events(pci->fd, 1, &pci->fdblock);
1915                                 if (events <= 0) {
1916                                         cpu_mark_offline(pdi, pci->cpu);
1917                                         close(pci->fd);
1918                                         pci->fd = -1;
1919                                         continue;
1920                                 }
1921
1922                                 if (pdi->last_read_time < last_allowed_time)
1923                                         last_allowed_time = pdi->last_read_time;
1924
1925                                 events_added += events;
1926                         }
1927                 }
1928
1929                 if (sort_entries(&youngest))
1930                         break;
1931
1932                 if (youngest > stopwatch_end)
1933                         break;
1934
1935                 show_entries_rb(0);
1936
1937         } while (events_added);
1938
1939         if (rb_sort_entries)
1940                 show_entries_rb(1);
1941
1942         return 0;
1943 }
1944
1945 static int do_stdin(void)
1946 {
1947         unsigned long long youngest;
1948         int fd, events, fdblock;
1949
1950         last_allowed_time = -1ULL;
1951         fd = dup(STDIN_FILENO);
1952         if (fd == -1) {
1953                 perror("dup stdin");
1954                 return -1;
1955         }
1956
1957         fdblock = -1;
1958         while ((events = read_events(fd, 0, &fdblock)) > 0) {
1959
1960 #if 0
1961                 smallest_seq_read = -1U;
1962 #endif
1963
1964                 if (sort_entries(&youngest))
1965                         break;
1966
1967                 if (youngest > stopwatch_end)
1968                         break;
1969
1970                 show_entries_rb(0);
1971         }
1972
1973         if (rb_sort_entries)
1974                 show_entries_rb(1);
1975
1976         close(fd);
1977         return 0;
1978 }
1979
1980 static void show_stats(void)
1981 {
1982         if (!ofp)
1983                 return;
1984         if (stats_printed)
1985                 return;
1986
1987         stats_printed = 1;
1988
1989         if (per_process_stats)
1990                 show_process_stats();
1991
1992         if (per_device_and_cpu_stats)
1993                 show_device_and_cpu_stats();
1994
1995         fflush(ofp);
1996 }
1997
1998 static void handle_sigint(__attribute__((__unused__)) int sig)
1999 {
2000         done = 1;
2001 }
2002
2003 /*
2004  * Extract start and duration times from a string, allowing
2005  * us to specify a time interval of interest within a trace.
2006  * Format: "duration" (start is zero) or "start:duration".
2007  */
2008 static int find_stopwatch_interval(char *string)
2009 {
2010         double value;
2011         char *sp;
2012
2013         value = strtod(string, &sp);
2014         if (sp == string) {
2015                 fprintf(stderr,"Invalid stopwatch timer: %s\n", string);
2016                 return 1;
2017         }
2018         if (*sp == ':') {
2019                 stopwatch_start = DOUBLE_TO_NANO_ULL(value);
2020                 string = sp + 1;
2021                 value = strtod(string, &sp);
2022                 if (sp == string || *sp != '\0') {
2023                         fprintf(stderr,"Invalid stopwatch duration time: %s\n",
2024                                 string);
2025                         return 1;
2026                 }
2027         } else if (*sp != '\0') {
2028                 fprintf(stderr,"Invalid stopwatch start timer: %s\n", string);
2029                 return 1;
2030         }
2031         stopwatch_end = DOUBLE_TO_NANO_ULL(value);
2032         if (stopwatch_end <= stopwatch_start) {
2033                 fprintf(stderr, "Invalid stopwatch interval: %Lu -> %Lu\n",
2034                         stopwatch_start, stopwatch_end);
2035                 return 1;
2036         }
2037
2038         return 0;
2039 }
2040
2041 static char usage_str[] = \
2042         "[ -i <input name> ] [-o <output name> [ -s ] [ -t ] [ -q ]\n" \
2043         "[ -w start:stop ] [ -f output format ] [ -F format spec ] [ -v] \n\n" \
2044         "\t-i Input file containing trace data, or '-' for stdin\n" \
2045         "\t-D Directory to prepend to input file names\n" \
2046         "\t-o Output file. If not given, output is stdout\n" \
2047         "\t-b stdin read batching\n" \
2048         "\t-s Show per-program io statistics\n" \
2049         "\t-h Hash processes by name, not pid\n" \
2050         "\t-t Track individual ios. Will tell you the time a request took\n" \
2051         "\t   to get queued, to get dispatched, and to get completed\n" \
2052         "\t-q Quiet. Don't display any stats at the end of the trace\n" \
2053         "\t-w Only parse data between the given time interval in seconds.\n" \
2054         "\t   If 'start' isn't given, blkparse defaults the start time to 0\n" \
2055         "\t-f Output format. Customize the output format. The format field\n" \
2056         "\t   identifies can be found in the documentation\n" \
2057         "\t-F Format specification. Can be found in the documentation\n" \
2058         "\t-v More verbose for marginal errors\n" \
2059         "\t-V Print program version info\n\n";
2060
2061 static void usage(char *prog)
2062 {
2063         fprintf(stderr, "Usage: %s %s %s", prog, blkparse_version, usage_str);
2064 }
2065
2066 int main(int argc, char *argv[])
2067 {
2068         char *ofp_buffer;
2069         int i, c, ret, mode;
2070         int act_mask_tmp = 0;
2071
2072         while ((c = getopt_long(argc, argv, S_OPTS, l_opts, NULL)) != -1) {
2073                 switch (c) {
2074                 case 'a':
2075                         i = find_mask_map(optarg);
2076                         if (i < 0) {
2077                                 fprintf(stderr,"Invalid action mask %s\n",
2078                                         optarg);
2079                                 return 1;
2080                         }
2081                         act_mask_tmp |= i;
2082                         break;
2083
2084                 case 'A':
2085                         if ((sscanf(optarg, "%x", &i) != 1) ||
2086                                                         !valid_act_opt(i)) {
2087                                 fprintf(stderr,
2088                                         "Invalid set action mask %s/0x%x\n",
2089                                         optarg, i);
2090                                 return 1;
2091                         }
2092                         act_mask_tmp = i;
2093                         break;
2094                 case 'i':
2095                         if (!strcmp(optarg, "-") && !pipeline)
2096                                 pipeline = 1;
2097                         else if (resize_devices(optarg) != 0)
2098                                 return 1;
2099                         break;
2100                 case 'D':
2101                         input_dir = optarg;
2102                         break;
2103                 case 'o':
2104                         output_name = optarg;
2105                         break;
2106                 case 'b':
2107                         rb_batch = atoi(optarg);
2108                         if (rb_batch <= 0)
2109                                 rb_batch = RB_BATCH_DEFAULT;
2110                         break;
2111                 case 's':
2112                         per_process_stats = 1;
2113                         break;
2114                 case 't':
2115                         track_ios = 1;
2116                         break;
2117                 case 'q':
2118                         per_device_and_cpu_stats = 0;
2119                         break;
2120                 case 'w':
2121                         if (find_stopwatch_interval(optarg) != 0)
2122                                 return 1;
2123                         break;
2124                 case 'f':
2125                         set_all_format_specs(optarg);
2126                         break;
2127                 case 'F':
2128                         if (add_format_spec(optarg) != 0)
2129                                 return 1;
2130                         break;
2131                 case 'h':
2132                         ppi_hash_by_pid = 0;
2133                         break;
2134                 case 'v':
2135                         verbose++;
2136                         break;
2137                 case 'V':
2138                         printf("%s version %s\n", argv[0], blkparse_version);
2139                         return 0;
2140                 default:
2141                         usage(argv[0]);
2142                         return 1;
2143                 }
2144         }
2145
2146         while (optind < argc) {
2147                 if (!strcmp(argv[optind], "-") && !pipeline)
2148                         pipeline = 1;
2149                 else if (resize_devices(argv[optind]) != 0)
2150                         return 1;
2151                 optind++;
2152         }
2153
2154         if (!pipeline && !ndevices) {
2155                 usage(argv[0]);
2156                 return 1;
2157         }
2158
2159         if (act_mask_tmp != 0)
2160                 act_mask = act_mask_tmp;
2161
2162         memset(&rb_sort_root, 0, sizeof(rb_sort_root));
2163
2164         signal(SIGINT, handle_sigint);
2165         signal(SIGHUP, handle_sigint);
2166         signal(SIGTERM, handle_sigint);
2167
2168         setlocale(LC_NUMERIC, "en_US");
2169
2170         if (!output_name) {
2171                 ofp = fdopen(STDOUT_FILENO, "w");
2172                 mode = _IOLBF;
2173         } else {
2174                 char ofname[128];
2175
2176                 snprintf(ofname, sizeof(ofname) - 1, "%s", output_name);
2177                 ofp = fopen(ofname, "w");
2178                 mode = _IOFBF;
2179         }
2180
2181         if (!ofp) {
2182                 perror("fopen");
2183                 return 1;
2184         }
2185
2186         ofp_buffer = malloc(4096);
2187         if (setvbuf(ofp, ofp_buffer, mode, 4096)) {
2188                 perror("setvbuf");
2189                 return 1;
2190         }
2191
2192         if (pipeline)
2193                 ret = do_stdin();
2194         else
2195                 ret = do_file();
2196
2197         show_stats();
2198         free(ofp_buffer);
2199         return ret;
2200 }