kvm/user/kvmtrace.c

   1 /*
   2  * kvm tracing application
   3  *
   4  * This tool is used for collecting trace buffer data
   5  * for kvm trace.
   6  *
   7  * Based on blktrace 0.99.3
   8  *
   9  * Copyright (C) 2005 Jens Axboe <axboe@suse.de>
  10  * Copyright (C) 2006 Jens Axboe <axboe@kernel.dk>
  11  * Copyright (C) 2008 Eric Liu <eric.e.liu@intel.com>
  12  *
  13  * This work is licensed under the GNU LGPL license, version 2.
  14  */
  15
  16 #define _GNU_SOURCE
  17
  18 #include <pthread.h>
  19 #include <sys/types.h>
  20 #include <sys/stat.h>
  21 #include <unistd.h>
  22 #include <signal.h>
  23 #include <fcntl.h>
  24 #include <string.h>
  25 #include <sys/ioctl.h>
  26 #include <sys/param.h>
  27 #include <sys/statfs.h>
  28 #include <sys/poll.h>
  29 #include <sys/mman.h>
  30 #include <stdio.h>
  31 #include <stdlib.h>
  32 #include <ctype.h>
  33 #include <getopt.h>
  34 #include <errno.h>
  35 #include <sched.h>
  36
  37 #ifndef __user
  38 #define __user
  39 #endif
  40 #include <linux/kvm.h>
  41
  42 static char kvmtrace_version[] = "0.1";
  43
  44 /*
  45  * You may want to increase this even more, if you are logging at a high
  46  * rate and see skipped/missed events
  47  */
  48 #define BUF_SIZE        (512 * 1024)
  49 #define BUF_NR          (8)
  50
  51 #define OFILE_BUF       (128 * 1024)
  52
  53 #define DEBUGFS_TYPE    0x64626720
  54
  55 #define max(a, b)       ((a) > (b) ? (a) : (b))
  56
  57 #define S_OPTS  "r:o:w:?Vb:n:D:"
  58 static struct option l_opts[] = {
  59         {
  60                 .name = "relay",
  61                 .has_arg = required_argument,
  62                 .flag = NULL,
  63                 .val = 'r'
  64         },
  65         {
  66                 .name = "output",
  67                 .has_arg = required_argument,
  68                 .flag = NULL,
  69                 .val = 'o'
  70         },
  71         {
  72                 .name = "stopwatch",
  73                 .has_arg = required_argument,
  74                 .flag = NULL,
  75                 .val = 'w'
  76         },
  77         {
  78                 .name = "version",
  79                 .has_arg = no_argument,
  80                 .flag = NULL,
  81                 .val = 'V'
  82         },
  83         {
  84                 .name = "buffer-size",
  85                 .has_arg = required_argument,
  86                 .flag = NULL,
  87                 .val = 'b'
  88         },
  89         {
  90                 .name = "num-sub-buffers",
  91                 .has_arg = required_argument,
  92                 .flag = NULL,
  93                 .val = 'n'
  94         },
  95         {
  96                 .name = "output-dir",
  97                 .has_arg = required_argument,
  98                 .flag = NULL,
  99                 .val = 'D'
 100         },
 101         {
 102                 .name = NULL,
 103         }
 104 };
 105
 106 struct thread_information {
 107         int cpu;
 108         pthread_t thread;
 109
 110         int fd;
 111         char fn[MAXPATHLEN + 64];
 112
 113         FILE *ofile;
 114         char *ofile_buffer;
 115
 116         int (*get_subbuf)(struct thread_information *, unsigned int);
 117         int (*read_data)(struct thread_information *, void *, unsigned int);
 118
 119         unsigned long long data_read;
 120
 121         struct kvm_trace_information *trace_info;
 122
 123         int exited;
 124
 125         /*
 126          * mmap controlled output files
 127          */
 128         unsigned long long fs_size;
 129         unsigned long long fs_max_size;
 130         unsigned long fs_off;
 131         void *fs_buf;
 132         unsigned long fs_buf_len;
 133
 134 };
 135
 136 struct kvm_trace_information {
 137         int fd;
 138         volatile int trace_started;
 139         unsigned long lost_records;
 140         struct thread_information *threads;
 141         unsigned long buf_size;
 142         unsigned long buf_nr;
 143 };
 144
 145 static struct kvm_trace_information trace_information;
 146
 147 static int ncpus;
 148 static char default_debugfs_path[] = "/sys/kernel/debug";
 149
 150 /* command line option globals */
 151 static char *debugfs_path;
 152 static char *output_name;
 153 static char *output_dir;
 154 static int stop_watch;
 155 static unsigned long buf_size = BUF_SIZE;
 156 static unsigned long buf_nr = BUF_NR;
 157 static unsigned int page_size;
 158
 159 #define for_each_cpu_online(cpu) \
 160         for (cpu = 0; cpu < ncpus; cpu++)
 161 #define for_each_tip(tip, i) \
 162         for (i = 0, tip = trace_information.threads; i < ncpus; i++, tip++)
 163
 164 #define is_done()       (*(volatile int *)(&done))
 165 static volatile int done;
 166
 167 #define is_trace_stopped()      (*(volatile int *)(&trace_stopped))
 168 static volatile int trace_stopped;
 169
 170 static void exit_trace(int status);
 171
 172 static void handle_sigint(__attribute__((__unused__)) int sig)
 173 {
 174         ioctl(trace_information.fd, KVM_TRACE_PAUSE);
 175         done = 1;
 176 }
 177
 178 static int get_lost_records()
 179 {
 180         int fd;
 181         char tmp[MAXPATHLEN + 64];
 182
 183         snprintf(tmp, sizeof(tmp), "%s/kvm/lost_records", debugfs_path);
 184         fd = open(tmp, O_RDONLY);
 185         if (fd < 0) {
 186                 /*
 187                  * this may be ok, if the kernel doesn't support dropped counts
 188                  */
 189                 if (errno == ENOENT)
 190                         return 0;
 191
 192                 fprintf(stderr, "Couldn't open dropped file %s\n", tmp);
 193                 return -1;
 194         }
 195
 196         if (read(fd, tmp, sizeof(tmp)) < 0) {
 197                 perror(tmp);
 198                 close(fd);
 199                 return -1;
 200         }
 201         close(fd);
 202
 203         return atoi(tmp);
 204 }
 205
 206 static void wait_for_data(struct thread_information *tip, int timeout)
 207 {
 208         struct pollfd pfd = { .fd = tip->fd, .events = POLLIN };
 209
 210         while (!is_done()) {
 211                 if (poll(&pfd, 1, timeout) < 0) {
 212                         perror("poll");
 213                         break;
 214                 }
 215                 if (pfd.revents & POLLIN)
 216                         break;
 217         }
 218 }
 219
 220 static int read_data(struct thread_information *tip, void *buf,
 221                           unsigned int len)
 222 {
 223         int ret = 0;
 224
 225         do {
 226                 wait_for_data(tip, 100);
 227
 228                 ret = read(tip->fd, buf, len);
 229
 230                 if (!ret)
 231                         continue;
 232                 else if (ret > 0)
 233                         return ret;
 234                 else {
 235                         if (errno != EAGAIN) {
 236                                 perror(tip->fn);
 237                                 fprintf(stderr, "Thread %d failed read of %s\n",
 238                                         tip->cpu, tip->fn);
 239                                 break;
 240                         }
 241                         continue;
 242                 }
 243         } while (!is_done());
 244
 245         return ret;
 246
 247 }
 248
 249 /*
 250  * For file output, truncate and mmap the file appropriately
 251  */
 252 static int mmap_subbuf(struct thread_information *tip, unsigned int maxlen)
 253 {
 254         int ofd = fileno(tip->ofile);
 255         int ret;
 256         unsigned long nr;
 257         unsigned long size;
 258
 259         /*
 260          * extend file, if we have to. use chunks of 16 subbuffers.
 261          */
 262         if (tip->fs_off + maxlen > tip->fs_buf_len) {
 263                 if (tip->fs_buf) {
 264                         munlock(tip->fs_buf, tip->fs_buf_len);
 265                         munmap(tip->fs_buf, tip->fs_buf_len);
 266                         tip->fs_buf = NULL;
 267                 }
 268
 269                 tip->fs_off = tip->fs_size & (page_size - 1);
 270                 nr = max(16, tip->trace_info->buf_nr);
 271                 size = tip->trace_info->buf_size;
 272                 tip->fs_buf_len = (nr * size) - tip->fs_off;
 273                 tip->fs_max_size += tip->fs_buf_len;
 274
 275                 if (ftruncate(ofd, tip->fs_max_size) < 0) {
 276                         perror("ftruncate");
 277                         return -1;
 278                 }
 279
 280                 tip->fs_buf = mmap(NULL, tip->fs_buf_len, PROT_WRITE,
 281                                    MAP_SHARED, ofd, tip->fs_size - tip->fs_off);
 282                 if (tip->fs_buf == MAP_FAILED) {
 283                         perror("mmap");
 284                         return -1;
 285                 }
 286                 mlock(tip->fs_buf, tip->fs_buf_len);
 287         }
 288
 289         ret = tip->read_data(tip, tip->fs_buf + tip->fs_off, maxlen);
 290         if (ret >= 0) {
 291                 tip->data_read += ret;
 292                 tip->fs_size += ret;
 293                 tip->fs_off += ret;
 294                 return 0;
 295         }
 296
 297         return -1;
 298 }
 299
 300 static void tip_ftrunc_final(struct thread_information *tip)
 301 {
 302         /*
 303          * truncate to right size and cleanup mmap
 304          */
 305         if (tip->ofile) {
 306                 int ofd = fileno(tip->ofile);
 307
 308                 if (tip->fs_buf)
 309                         munmap(tip->fs_buf, tip->fs_buf_len);
 310
 311                 ftruncate(ofd, tip->fs_size);
 312         }
 313 }
 314
 315 static void *thread_main(void *arg)
 316 {
 317         struct thread_information *tip = arg;
 318         pid_t pid = getpid();
 319         cpu_set_t cpu_mask;
 320
 321         CPU_ZERO(&cpu_mask);
 322         CPU_SET((tip->cpu), &cpu_mask);
 323
 324         if (sched_setaffinity(pid, sizeof(cpu_mask), &cpu_mask) == -1) {
 325                 perror("sched_setaffinity");
 326                 exit_trace(1);
 327         }
 328
 329         snprintf(tip->fn, sizeof(tip->fn), "%s/kvm/trace%d",
 330                         debugfs_path, tip->cpu);
 331         tip->fd = open(tip->fn, O_RDONLY);
 332         if (tip->fd < 0) {
 333                 perror(tip->fn);
 334                 fprintf(stderr, "Thread %d failed open of %s\n", tip->cpu,
 335                         tip->fn);
 336                 exit_trace(1);
 337         }
 338         while (!is_done()) {
 339                 if (tip->get_subbuf(tip, tip->trace_info->buf_size) < 0)
 340                         break;
 341         }
 342
 343         /*
 344          * trace is stopped, pull data until we get a short read
 345          */
 346         while (tip->get_subbuf(tip, tip->trace_info->buf_size) > 0)
 347                 ;
 348
 349         tip_ftrunc_final(tip);
 350         tip->exited = 1;
 351         return NULL;
 352 }
 353
 354 static int fill_ofname(struct thread_information *tip, char *dst)
 355 {
 356         struct stat sb;
 357         int len = 0;
 358
 359         if (output_dir)
 360                 len = sprintf(dst, "%s/", output_dir);
 361         else
 362                 len = sprintf(dst, "./");
 363
 364         if (stat(dst, &sb) < 0) {
 365                 if (errno != ENOENT) {
 366                         perror("stat");
 367                         return 1;
 368                 }
 369                 if (mkdir(dst, 0755) < 0) {
 370                         perror(dst);
 371                         fprintf(stderr, "Can't make output dir\n");
 372                         return 1;
 373                 }
 374         }
 375
 376         sprintf(dst + len, "%s.kvmtrace.%d", output_name, tip->cpu);
 377
 378         return 0;
 379 }
 380
 381 static void fill_ops(struct thread_information *tip)
 382 {
 383         tip->get_subbuf = mmap_subbuf;
 384         tip->read_data = read_data;
 385 }
 386
 387 static void close_thread(struct thread_information *tip)
 388 {
 389         if (tip->fd != -1)
 390                 close(tip->fd);
 391         if (tip->ofile)
 392                 fclose(tip->ofile);
 393         if (tip->ofile_buffer)
 394                 free(tip->ofile_buffer);
 395
 396         tip->fd = -1;
 397         tip->ofile = NULL;
 398         tip->ofile_buffer = NULL;
 399 }
 400
 401 static int tip_open_output(struct thread_information *tip)
 402 {
 403         int mode, vbuf_size;
 404         char op[NAME_MAX];
 405
 406         if (fill_ofname(tip, op))
 407                 return 1;
 408
 409         tip->ofile = fopen(op, "w+");
 410         mode = _IOFBF;
 411         vbuf_size = OFILE_BUF;
 412
 413         if (tip->ofile == NULL) {
 414                 perror(op);
 415                 return 1;
 416         }
 417
 418         tip->ofile_buffer = malloc(vbuf_size);
 419         if (setvbuf(tip->ofile, tip->ofile_buffer, mode, vbuf_size)) {
 420                 perror("setvbuf");
 421                 close_thread(tip);
 422                 return 1;
 423         }
 424
 425         fill_ops(tip);
 426         return 0;
 427 }
 428
 429 static int start_threads(int cpu)
 430 {
 431         struct thread_information *tip;
 432
 433         tip = trace_information.threads + cpu;
 434         tip->cpu = cpu;
 435         tip->trace_info = &trace_information;
 436         tip->fd = -1;
 437
 438         if (tip_open_output(tip))
 439             return 1;
 440
 441         if (pthread_create(&tip->thread, NULL, thread_main, tip)) {
 442                 perror("pthread_create");
 443                 close_thread(tip);
 444                 return 1;
 445         }
 446
 447         return 0;
 448 }
 449
 450 static void stop_threads()
 451 {
 452         struct thread_information *tip;
 453         unsigned long ret;
 454         int i;
 455
 456         for_each_tip(tip, i) {
 457                 (void) pthread_join(tip->thread, (void *) &ret);
 458                 close_thread(tip);
 459         }
 460 }
 461
 462 static int start_trace(void)
 463 {
 464         int fd;
 465         struct kvm_user_trace_setup kuts;
 466
 467         fd = trace_information.fd = open("/dev/kvm", O_RDWR);
 468         if (fd == -1) {
 469                 perror("/dev/kvm");
 470                 return 1;
 471         }
 472
 473         memset(&kuts, 0, sizeof(kuts));
 474         kuts.buf_size = trace_information.buf_size = buf_size;
 475         kuts.buf_nr = trace_information.buf_nr = buf_nr;
 476
 477         if (ioctl(trace_information.fd , KVM_TRACE_ENABLE, &kuts) < 0) {
 478                 perror("KVM_TRACE_ENABLE");
 479                 close(fd);
 480                 return 1;
 481         }
 482         trace_information.trace_started = 1;
 483
 484         return 0;
 485 }
 486
 487 static void cleanup_trace(void)
 488 {
 489         if (trace_information.fd == -1)
 490                 return;
 491
 492         trace_information.lost_records = get_lost_records();
 493
 494         if (trace_information.trace_started) {
 495                 trace_information.trace_started = 0;
 496                 if (ioctl(trace_information.fd, KVM_TRACE_DISABLE) < 0)
 497                         perror("KVM_TRACE_DISABLE");
 498         }
 499
 500         close(trace_information.fd);
 501         trace_information.fd  = -1;
 502 }
 503
 504 static void stop_all_traces(void)
 505 {
 506         if (!is_trace_stopped()) {
 507                 trace_stopped = 1;
 508                 stop_threads();
 509                 cleanup_trace();
 510         }
 511 }
 512
 513 static void exit_trace(int status)
 514 {
 515         stop_all_traces();
 516         exit(status);
 517 }
 518
 519 static int start_kvm_trace(void)
 520 {
 521         int i, size;
 522         struct thread_information *tip;
 523
 524         size = ncpus * sizeof(struct thread_information);
 525         tip = malloc(size);
 526         if (!tip) {
 527                 fprintf(stderr, "Out of memory, threads (%d)\n", size);
 528                 return 1;
 529         }
 530         memset(tip, 0, size);
 531         trace_information.threads = tip;
 532
 533         if (start_trace())
 534                 return 1;
 535
 536         for_each_cpu_online(i) {
 537                 if (start_threads(i)) {
 538                         fprintf(stderr, "Failed to start worker threads\n");
 539                         break;
 540                 }
 541         }
 542
 543         if (i != ncpus) {
 544                 stop_threads();
 545                 cleanup_trace();
 546                 return 1;
 547         }
 548
 549         return 0;
 550 }
 551
 552 static void wait_for_threads(void)
 553 {
 554         struct thread_information *tip;
 555         int i, tips_running;
 556
 557         do {
 558                 tips_running = 0;
 559                 usleep(100000);
 560
 561                 for_each_tip(tip, i)
 562                         tips_running += !tip->exited;
 563
 564         } while (tips_running);
 565 }
 566
 567 static void show_stats(void)
 568 {
 569         struct thread_information *tip;
 570         unsigned long long data_read;
 571         int i;
 572
 573         data_read = 0;
 574         for_each_tip(tip, i) {
 575                 printf("  CPU%3d: %8llu KiB data\n",
 576                         tip->cpu, (tip->data_read + 1023) >> 10);
 577                 data_read += tip->data_read;
 578         }
 579
 580         printf("  Total:  lost %lu, %8llu KiB data\n",
 581                 trace_information.lost_records, (data_read + 1023) >> 10);
 582
 583         if (trace_information.lost_records)
 584                 fprintf(stderr, "You have lost records, "
 585                                 "consider using a larger buffer size (-b)\n");
 586 }
 587
 588 static char usage_str[] = \
 589         "[ -r debugfs path ] [ -D output dir ] [ -b buffer size ]\n" \
 590         "[ -n number of buffers] [ -o <output file> ] [ -w time  ] [ -V ]\n\n" \
 591         "\t-r Path to mounted debugfs, defaults to /sys/kernel/debug\n" \
 592         "\t-o File(s) to send output to\n" \
 593         "\t-D Directory to prepend to output file names\n" \
 594         "\t-w Stop after defined time, in seconds\n" \
 595         "\t-b Sub buffer size in KiB\n" \
 596         "\t-n Number of sub buffers\n" \
 597         "\t-V Print program version info\n\n";
 598
 599 static void show_usage(char *prog)
 600 {
 601         fprintf(stderr, "Usage: %s %s %s", prog, kvmtrace_version, usage_str);
 602         exit(EXIT_FAILURE);
 603 }
 604
 605 void parse_args(int argc, char **argv)
 606 {
 607         int c;
 608
 609         while ((c = getopt_long(argc, argv, S_OPTS, l_opts, NULL)) >= 0) {
 610                 switch (c) {
 611                 case 'r':
 612                         debugfs_path = optarg;
 613                         break;
 614                 case 'o':
 615                         output_name = optarg;
 616                         break;
 617                 case 'w':
 618                         stop_watch = atoi(optarg);
 619                         if (stop_watch <= 0) {
 620                                 fprintf(stderr,
 621                                         "Invalid stopwatch value (%d secs)\n",
 622                                         stop_watch);
 623                                 exit(EXIT_FAILURE);
 624                         }
 625                         break;
 626                 case 'V':
 627                         printf("%s version %s\n", argv[0], kvmtrace_version);
 628                         exit(EXIT_SUCCESS);
 629                 case 'b':
 630                         buf_size = strtoul(optarg, NULL, 10);
 631                         if (buf_size <= 0 || buf_size > 16*1024) {
 632                                 fprintf(stderr,
 633                                         "Invalid buffer size (%lu)\n",
 634                                         buf_size);
 635                                 exit(EXIT_FAILURE);
 636                         }
 637                         buf_size <<= 10;
 638                         break;
 639                 case 'n':
 640                         buf_nr = strtoul(optarg, NULL, 10);
 641                         if (buf_nr <= 0) {
 642                                 fprintf(stderr,
 643                                         "Invalid buffer nr (%lu)\n", buf_nr);
 644                                 exit(EXIT_FAILURE);
 645                         }
 646                         break;
 647                 case 'D':
 648                         output_dir = optarg;
 649                         break;
 650                 default:
 651                         show_usage(argv[0]);
 652                 }
 653         }
 654
 655         if (optind < argc || output_name == NULL)
 656                 show_usage(argv[0]);
 657 }
 658
 659 int main(int argc, char *argv[])
 660 {
 661         struct statfs st;
 662
 663         parse_args(argc, argv);
 664
 665         if (!debugfs_path)
 666                 debugfs_path = default_debugfs_path;
 667
 668         if (statfs(debugfs_path, &st) < 0) {
 669                 perror("statfs");
 670                 fprintf(stderr, "%s does not appear to be a valid path\n",
 671                         debugfs_path);
 672                 return 1;
 673         } else if (st.f_type != (long) DEBUGFS_TYPE) {
 674                 fprintf(stderr, "%s does not appear to be a debug filesystem,"
 675                         " please mount debugfs.\n",
 676                         debugfs_path);
 677                 return 1;
 678         }
 679
 680         page_size = getpagesize();
 681
 682         ncpus = sysconf(_SC_NPROCESSORS_ONLN);
 683         if (ncpus < 0) {
 684                 fprintf(stderr, "sysconf(_SC_NPROCESSORS_ONLN) failed\n");
 685                 return 1;
 686         }
 687
 688         signal(SIGINT, handle_sigint);
 689         signal(SIGHUP, handle_sigint);
 690         signal(SIGTERM, handle_sigint);
 691         signal(SIGALRM, handle_sigint);
 692         signal(SIGPIPE, SIG_IGN);
 693
 694         if (start_kvm_trace() != 0)
 695                 return 1;
 696
 697         if (stop_watch)
 698                 alarm(stop_watch);
 699
 700         wait_for_threads();
 701         stop_all_traces();
 702         show_stats();
 703
 704         return 0;
 705 }