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