1 /*- 2 * Copyright (c) 2002 Jake Burkholder 3 * Copyright (c) 2004 Robert Watson 4 * All rights reserved. 5 * 6 * Redistribution and use in source and binary forms, with or without 7 * modification, are permitted provided that the following conditions 8 * are met: 9 * 1. Redistributions of source code must retain the above copyright 10 * notice, this list of conditions and the following disclaimer. 11 * 2. Redistributions in binary form must reproduce the above copyright 12 * notice, this list of conditions and the following disclaimer in the 13 * documentation and/or other materials provided with the distribution. 14 * 15 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND 16 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE 17 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE 18 * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE 19 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL 20 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS 21 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) 22 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT 23 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY 24 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF 25 * SUCH DAMAGE. 26 * 27 * $FreeBSD: src/usr.bin/ktrdump/ktrdump.c,v 1.10 2005/05/21 09:55:06 ru Exp $ 28 * $DragonFly: src/usr.bin/ktrdump/ktrdump.c,v 1.11 2008/02/17 10:23:57 corecode Exp $ 29 */ 30 31 #include <sys/cdefs.h> 32 33 #include <sys/types.h> 34 #include <sys/ktr.h> 35 #include <sys/mman.h> 36 #include <sys/stat.h> 37 #include <sys/queue.h> 38 39 #include <err.h> 40 #include <fcntl.h> 41 #include <kvm.h> 42 #include <limits.h> 43 #include <nlist.h> 44 #include <stdint.h> 45 #include <stdio.h> 46 #include <stdlib.h> 47 #include <string.h> 48 #include <unistd.h> 49 50 #define SBUFLEN 128 51 52 extern char *optarg; 53 extern int optind; 54 55 struct ktr_buffer { 56 struct ktr_entry *ents; 57 int modified; 58 int reset; 59 int beg_idx; /* Beginning index */ 60 int end_idx; /* Ending index */ 61 }; 62 63 static struct nlist nl[] = { 64 { "_ktr_version" }, 65 { "_ktr_entries" }, 66 { "_ktr_idx" }, 67 { "_ktr_buf" }, 68 { "_ncpus" }, 69 { NULL } 70 }; 71 static struct nlist nl2[] = { 72 { "_tsc_frequency" }, 73 { NULL } 74 }; 75 76 static int cflag; 77 static int fflag; 78 static int iflag; 79 static int lflag; 80 static int nflag; 81 static int qflag; 82 static int rflag; 83 static int sflag; 84 static int tflag; 85 static int xflag; 86 static int pflag; 87 static int Mflag; 88 static int Nflag; 89 static double tsc_frequency; 90 static double correction_factor = 0.0; 91 92 static char corefile[PATH_MAX]; 93 static char execfile[PATH_MAX]; 94 95 static char errbuf[_POSIX2_LINE_MAX]; 96 static int ncpus; 97 static kvm_t *kd; 98 static int entries_per_buf; 99 static int fifo_mask; 100 101 static void usage(void); 102 static int earliest_ts(struct ktr_buffer *buf); 103 static void print_header(FILE *fo, int row); 104 static void print_entry(FILE *fo, kvm_t *kd, int n, int i, struct ktr_entry *entry, u_int64_t *last_timestamp); 105 static struct ktr_info *kvm_ktrinfo(kvm_t *kd, void *kptr); 106 static const char *kvm_string(kvm_t *kd, const char *kptr); 107 static const char *trunc_path(const char *str, int maxlen); 108 static void read_symbols(const char *execfile); 109 static const char *address_to_symbol(void *kptr); 110 static struct ktr_buffer *ktr_bufs_init(int); 111 static void load_bufs(struct ktr_buffer *, struct ktr_entry **); 112 static void print_buf(FILE *, struct ktr_buffer *, int, u_int64_t *); 113 static void print_bufs_timesorted(FILE *, struct ktr_buffer *, u_int64_t *); 114 115 116 /* 117 * Reads the ktr trace buffer from kernel memory and prints the trace entries. 118 */ 119 int 120 main(int ac, char **av) 121 { 122 struct ktr_buffer *ktr_bufs; 123 struct ktr_entry **ktr_kbuf; 124 FILE *fo; 125 int64_t tts; 126 int *ktr_start_index; 127 int version; 128 int c; 129 int n; 130 131 /* 132 * Parse commandline arguments. 133 */ 134 fo = stdout; 135 while ((c = getopt(ac, av, "acfinqrtxpslA:N:M:o:")) != -1) { 136 switch (c) { 137 case 'a': 138 cflag = 1; 139 iflag = 1; 140 rflag = 1; 141 xflag = 1; 142 pflag = 1; 143 rflag = 1; 144 sflag = 1; 145 break; 146 case 'c': 147 cflag = 1; 148 break; 149 case 'N': 150 if (strlcpy(execfile, optarg, sizeof(execfile)) 151 >= sizeof(execfile)) 152 errx(1, "%s: File name too long", optarg); 153 Nflag = 1; 154 break; 155 case 'f': 156 fflag = 1; 157 break; 158 case 'l': 159 lflag = 1; 160 break; 161 case 'i': 162 iflag = 1; 163 break; 164 case 'A': 165 correction_factor = strtod(optarg, NULL); 166 break; 167 case 'M': 168 if (strlcpy(corefile, optarg, sizeof(corefile)) 169 >= sizeof(corefile)) 170 errx(1, "%s: File name too long", optarg); 171 Mflag = 1; 172 break; 173 case 'n': 174 nflag = 1; 175 break; 176 case 'o': 177 if ((fo = fopen(optarg, "w")) == NULL) 178 err(1, "%s", optarg); 179 break; 180 case 'p': 181 pflag++; 182 break; 183 case 'q': 184 qflag++; 185 break; 186 case 'r': 187 rflag = 1; 188 break; 189 case 's': 190 sflag = 1; /* sort across the cpus */ 191 break; 192 case 't': 193 tflag = 1; 194 break; 195 case 'x': 196 xflag = 1; 197 break; 198 case '?': 199 default: 200 usage(); 201 } 202 } 203 if (cflag + iflag + tflag + xflag + fflag + pflag == 0) { 204 cflag = 1; 205 iflag = 1; 206 tflag = 1; 207 pflag = 1; 208 } 209 if (correction_factor != 0.0 && (rflag == 0 || nflag)) { 210 fprintf(stderr, "Correction factor can only be applied with -r and without -n\n"); 211 exit(1); 212 } 213 ac -= optind; 214 av += optind; 215 if (ac != 0) 216 usage(); 217 218 /* 219 * Open our execfile and corefile, resolve needed symbols and read in 220 * the trace buffer. 221 */ 222 if ((kd = kvm_openfiles(Nflag ? execfile : NULL, 223 Mflag ? corefile : NULL, NULL, O_RDONLY, errbuf)) == NULL) 224 errx(1, "%s", errbuf); 225 if (kvm_nlist(kd, nl) != 0) 226 errx(1, "%s", kvm_geterr(kd)); 227 if (kvm_read(kd, nl[0].n_value, &version, sizeof(version)) == -1) 228 errx(1, "%s", kvm_geterr(kd)); 229 if (kvm_read(kd, nl[4].n_value, &ncpus, sizeof(ncpus)) == -1) 230 errx(1, "%s", kvm_geterr(kd)); 231 ktr_start_index = malloc(sizeof(*ktr_start_index) * ncpus); 232 if (version >= 3 && kvm_nlist(kd, nl2) == 0) { 233 if (kvm_read(kd, nl2[0].n_value, &tts, sizeof(tts)) == -1) 234 errx(1, "%s", kvm_geterr(kd)); 235 tsc_frequency = (double)tts; 236 } 237 if (version > KTR_VERSION) 238 errx(1, "ktr version too high for us to handle"); 239 if (kvm_read(kd, nl[1].n_value, &entries_per_buf, 240 sizeof(entries_per_buf)) == -1) 241 errx(1, "%s", kvm_geterr(kd)); 242 fifo_mask = entries_per_buf - 1; 243 244 printf("TSC frequency is %6.3f MHz\n", tsc_frequency / 1000000.0); 245 246 ktr_kbuf = malloc(sizeof(*ktr_kbuf) * ncpus); 247 248 if (nflag == 0) 249 read_symbols(Nflag ? execfile : NULL); 250 251 if (kvm_read(kd, nl[3].n_value, ktr_kbuf, sizeof(*ktr_kbuf) * ncpus) == -1) 252 errx(1, "%s", kvm_geterr(kd)); 253 254 ktr_bufs = ktr_bufs_init(ncpus); 255 256 if (sflag) { 257 u_int64_t last_timestamp = 0; 258 do { 259 load_bufs(ktr_bufs, ktr_kbuf); 260 print_bufs_timesorted(fo, ktr_bufs, &last_timestamp); 261 if (lflag) 262 usleep(1000000 / 10); 263 } while (lflag); 264 } else { 265 u_int64_t *last_timestamp = calloc(sizeof(u_int64_t), ncpus); 266 do { 267 load_bufs(ktr_bufs, ktr_kbuf); 268 for (n = 0; n < ncpus; ++n) 269 print_buf(fo, ktr_bufs, n, &last_timestamp[n]); 270 if (lflag) 271 usleep(1000000 / 10); 272 } while (lflag); 273 } 274 return (0); 275 } 276 277 static void 278 print_header(FILE *fo, int row) 279 { 280 if (qflag == 0 && (u_int32_t)row % 20 == 0) { 281 fprintf(fo, "%-6s ", "index"); 282 if (cflag) 283 fprintf(fo, "%-3s ", "cpu"); 284 if (tflag || rflag) 285 fprintf(fo, "%-16s ", "timestamp"); 286 if (xflag) { 287 if (nflag) 288 fprintf(fo, "%-10s %-10s", "caller2", "caller1"); 289 else 290 fprintf(fo, "%-20s %-20s", "caller2", "caller1"); 291 } 292 if (iflag) 293 fprintf(fo, "%-20s ", "ID"); 294 if (fflag) 295 fprintf(fo, "%10s%-30s ", "", "file and line"); 296 if (pflag) 297 fprintf(fo, "%s", "trace"); 298 fprintf(fo, "\n"); 299 } 300 } 301 302 static void 303 print_entry(FILE *fo, kvm_t *kd, int n, int row, struct ktr_entry *entry, 304 u_int64_t *last_timestamp) 305 { 306 struct ktr_info *info = NULL; 307 308 fprintf(fo, " %06x ", row & 0x00FFFFFF); 309 if (cflag) 310 fprintf(fo, "%-3d ", n); 311 if (tflag || rflag) { 312 if (rflag && !nflag && tsc_frequency != 0.0) { 313 fprintf(fo, "%13.3f uS ", 314 (double)(entry->ktr_timestamp - *last_timestamp) * 1000000.0 / tsc_frequency - correction_factor); 315 } else if (rflag) { 316 fprintf(fo, "%-16lld ", entry->ktr_timestamp - 317 *last_timestamp); 318 } else { 319 fprintf(fo, "%-16lld ", entry->ktr_timestamp); 320 } 321 } 322 if (xflag) { 323 if (nflag) { 324 fprintf(fo, "%p %p ", 325 entry->ktr_caller2, entry->ktr_caller1); 326 } else { 327 fprintf(fo, "%-20s ", 328 address_to_symbol(entry->ktr_caller2)); 329 fprintf(fo, "%-20s ", 330 address_to_symbol(entry->ktr_caller1)); 331 } 332 } 333 if (iflag) { 334 info = kvm_ktrinfo(kd, entry->ktr_info); 335 if (info) 336 fprintf(fo, "%-20s ", kvm_string(kd, info->kf_name)); 337 else 338 fprintf(fo, "%-20s ", "<empty>"); 339 } 340 if (fflag) 341 fprintf(fo, "%34s:%-4d ", trunc_path(kvm_string(kd, entry->ktr_file), 34), entry->ktr_line); 342 if (pflag) { 343 if (info == NULL) 344 info = kvm_ktrinfo(kd, entry->ktr_info); 345 if (info) { 346 fprintf(fo, kvm_string(kd, info->kf_format), 347 entry->ktr_data[0], entry->ktr_data[1], 348 entry->ktr_data[2], entry->ktr_data[3], 349 entry->ktr_data[4], entry->ktr_data[5], 350 entry->ktr_data[6], entry->ktr_data[7], 351 entry->ktr_data[8], entry->ktr_data[9]); 352 } else { 353 fprintf(fo, ""); 354 } 355 } 356 fprintf(fo, "\n"); 357 *last_timestamp = entry->ktr_timestamp; 358 } 359 360 static 361 struct ktr_info * 362 kvm_ktrinfo(kvm_t *kd, void *kptr) 363 { 364 static struct ktr_info save_info; 365 static void *save_kptr; 366 367 if (kptr == NULL) 368 return(NULL); 369 if (save_kptr != kptr) { 370 if (kvm_read(kd, (uintptr_t)kptr, &save_info, sizeof(save_info)) == -1) { 371 bzero(&save_info, sizeof(save_info)); 372 } else { 373 save_kptr = kptr; 374 } 375 } 376 return(&save_info); 377 } 378 379 static 380 const char * 381 kvm_string(kvm_t *kd, const char *kptr) 382 { 383 static char save_str[128]; 384 static const char *save_kptr; 385 int l; 386 int n; 387 388 if (kptr == NULL) 389 return("?"); 390 if (save_kptr != kptr) { 391 save_kptr = kptr; 392 l = 0; 393 while (l < sizeof(save_str) - 1) { 394 n = 256 - ((intptr_t)(kptr + l) & 255); 395 if (n > sizeof(save_str) - l - 1) 396 n = sizeof(save_str) - l - 1; 397 if (kvm_read(kd, (uintptr_t)(kptr + l), save_str + l, n) < 0) 398 break; 399 while (l < sizeof(save_str) && n) { 400 if (save_str[l] == 0) 401 break; 402 --n; 403 ++l; 404 } 405 if (n) 406 break; 407 } 408 save_str[l] = 0; 409 } 410 return(save_str); 411 } 412 413 static 414 const char * 415 trunc_path(const char *str, int maxlen) 416 { 417 int len = strlen(str); 418 419 if (len > maxlen) 420 return(str + len - maxlen); 421 else 422 return(str); 423 } 424 425 struct symdata { 426 TAILQ_ENTRY(symdata) link; 427 const char *symname; 428 char *symaddr; 429 char symtype; 430 }; 431 432 static TAILQ_HEAD(symlist, symdata) symlist; 433 static struct symdata *symcache; 434 static char *symbegin; 435 static char *symend; 436 437 static 438 void 439 read_symbols(const char *execfile) 440 { 441 char buf[256]; 442 char cmd[256]; 443 int buflen = sizeof(buf); 444 FILE *fp; 445 struct symdata *sym; 446 char *s1; 447 char *s2; 448 char *s3; 449 450 TAILQ_INIT(&symlist); 451 452 if (execfile == NULL) { 453 if (sysctlbyname("kern.bootfile", buf, &buflen, NULL, 0) < 0) 454 execfile = "/kernel"; 455 else 456 execfile = buf; 457 } 458 snprintf(cmd, sizeof(cmd), "nm -n %s", execfile); 459 if ((fp = popen(cmd, "r")) != NULL) { 460 while (fgets(buf, sizeof(buf), fp) != NULL) { 461 s1 = strtok(buf, " \t\n"); 462 s2 = strtok(NULL, " \t\n"); 463 s3 = strtok(NULL, " \t\n"); 464 if (s1 && s2 && s3) { 465 sym = malloc(sizeof(struct symdata)); 466 sym->symaddr = (char *)strtoul(s1, NULL, 16); 467 sym->symtype = s2[0]; 468 sym->symname = strdup(s3); 469 if (strcmp(s3, "kernbase") == 0) 470 symbegin = sym->symaddr; 471 if (strcmp(s3, "end") == 0) 472 symend = sym->symaddr; 473 TAILQ_INSERT_TAIL(&symlist, sym, link); 474 } 475 } 476 pclose(fp); 477 } 478 symcache = TAILQ_FIRST(&symlist); 479 } 480 481 static 482 const char * 483 address_to_symbol(void *kptr) 484 { 485 static char buf[64]; 486 487 if (symcache == NULL || 488 (char *)kptr < symbegin || (char *)kptr >= symend 489 ) { 490 snprintf(buf, sizeof(buf), "%p", kptr); 491 return(buf); 492 } 493 while ((char *)symcache->symaddr < (char *)kptr) { 494 if (TAILQ_NEXT(symcache, link) == NULL) 495 break; 496 symcache = TAILQ_NEXT(symcache, link); 497 } 498 while ((char *)symcache->symaddr > (char *)kptr) { 499 if (symcache != TAILQ_FIRST(&symlist)) 500 symcache = TAILQ_PREV(symcache, symlist, link); 501 } 502 snprintf(buf, sizeof(buf), "%s+%d", symcache->symname, 503 (int)((char *)kptr - symcache->symaddr)); 504 return(buf); 505 } 506 507 static 508 struct ktr_buffer * 509 ktr_bufs_init(int ncpus) 510 { 511 struct ktr_buffer *ktr_bufs, *it; 512 int i; 513 514 ktr_bufs = malloc(sizeof(*ktr_bufs) * ncpus); 515 if (!ktr_bufs) 516 err(1, "can't allocate data structures\n"); 517 for (i = 0; i < ncpus; ++i) { 518 it = ktr_bufs + i; 519 it->ents = malloc(sizeof(struct ktr_entry) * entries_per_buf); 520 if (it->ents == NULL) 521 err(1, "can't allocate data structures\n"); 522 it->reset = 1; 523 it->beg_idx = -1; 524 it->end_idx = -1; 525 } 526 return ktr_bufs; 527 } 528 529 static 530 void 531 get_indices(kvm_t *kd, int *idx) 532 { 533 if (kvm_read(kd, nl[2].n_value, idx, sizeof(*idx) * ncpus) == -1) 534 errx(1, "%s", kvm_geterr(kd)); 535 } 536 537 /* 538 * Get the trace buffer data from the kernel 539 */ 540 static 541 void 542 load_bufs(struct ktr_buffer *ktr_bufs, struct ktr_entry **kbufs) 543 { 544 static int *kern_idx; 545 struct ktr_buffer *kbuf; 546 int i; 547 548 if (!kern_idx) { 549 kern_idx = malloc(sizeof(*kern_idx) * ncpus); 550 if (!kern_idx) { 551 err(1, "can't allocate data structures\n"); 552 } 553 } 554 555 get_indices(kd, kern_idx); 556 for (i = 0; i < ncpus; ++i) { 557 kbuf = &ktr_bufs[i]; 558 if (kern_idx[i] == kbuf->end_idx) 559 continue; 560 kbuf->end_idx = kern_idx[i]; 561 562 /* 563 * If we do not have a notion of the beginning index, assume 564 * it is entries_per_buf before the ending index. Don't 565 * worry about underflows/negative numbers, the indices will 566 * be masked. 567 */ 568 if (kbuf->reset) { 569 kbuf->beg_idx = kbuf->end_idx - entries_per_buf + 1; 570 kbuf->reset = 0; 571 } 572 if (kvm_read(kd, (uintptr_t)kbufs[i], ktr_bufs[i].ents, 573 sizeof(struct ktr_entry) * entries_per_buf) 574 == -1) 575 errx(1, "%s", kvm_geterr(kd)); 576 kbuf->modified = 1; 577 kbuf->beg_idx = earliest_ts(kbuf); 578 } 579 580 } 581 582 /* 583 * Locate the earliest timestamp iterating backwards from end_idx, but 584 * not going further back then beg_idx. We have to do this because 585 * the kernel uses a circulating buffer. 586 */ 587 static 588 int 589 earliest_ts(struct ktr_buffer *buf) 590 { 591 struct ktr_entry *save; 592 int count, scan, i, earliest; 593 594 count = 0; 595 earliest = buf->end_idx - 1; 596 save = &buf->ents[earliest & fifo_mask]; 597 for (scan = buf->end_idx - 1; scan != buf->beg_idx -1; --scan) { 598 i = scan & fifo_mask; 599 if (buf->ents[i].ktr_timestamp <= save->ktr_timestamp) 600 earliest = scan; 601 /* 602 * We may have gotten so far behind that beg_idx wrapped 603 * more then once around the buffer. Just stop 604 */ 605 if (++count == entries_per_buf) 606 break; 607 } 608 return earliest; 609 } 610 611 static 612 void 613 print_buf(FILE *fo, struct ktr_buffer *ktr_bufs, int cpu, 614 u_int64_t *last_timestamp) 615 { 616 int first, last; 617 struct ktr_buffer *buf = ktr_bufs + cpu; 618 619 if (buf->modified == 0) 620 return; 621 if (*last_timestamp == 0) { 622 *last_timestamp = 623 buf->ents[buf->beg_idx & fifo_mask].ktr_timestamp; 624 } 625 while (buf->beg_idx != buf->end_idx) { 626 print_header(fo, buf->beg_idx); 627 print_entry(fo, kd, cpu, buf->beg_idx, 628 &buf->ents[buf->beg_idx & fifo_mask], 629 last_timestamp); 630 ++buf->beg_idx; 631 } 632 buf->modified = 0; 633 } 634 635 static 636 void 637 print_bufs_timesorted(FILE *fo, struct ktr_buffer *ktr_bufs, 638 u_int64_t *last_timestamp) 639 { 640 struct ktr_entry *ent; 641 struct ktr_buffer *buf; 642 int n, bestn; 643 u_int64_t ts; 644 static int row = 0; 645 646 for (;;) { 647 ts = 0; 648 bestn = -1; 649 for (n = 0; n < ncpus; ++n) { 650 buf = ktr_bufs + n; 651 if (buf->beg_idx == buf->end_idx) 652 continue; 653 ent = &buf->ents[buf->beg_idx & fifo_mask]; 654 if (ts == 0 || (ts >= ent->ktr_timestamp)) { 655 ts = ent->ktr_timestamp; 656 bestn = n; 657 } 658 } 659 if ((bestn < 0) || (ts < *last_timestamp)) 660 break; 661 buf = ktr_bufs + bestn; 662 print_header(fo, row); 663 print_entry(fo, kd, bestn, row, 664 &buf->ents[buf->beg_idx & fifo_mask], 665 last_timestamp); 666 ++buf->beg_idx; 667 *last_timestamp = ts; 668 ++row; 669 } 670 } 671 672 static void 673 usage(void) 674 { 675 fprintf(stderr, "usage: ktrdump [-acfilnpqrtx] [-N execfile] " 676 "[-M corefile] [-o outfile]\n"); 677 exit(1); 678 } 679