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.9 2007/06/08 18:46:32 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 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 { "_tsc_frequency" }, 70 { 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 *buf); 100 static void print_header(FILE *fo, int row); 101 static void print_entry(FILE *fo, kvm_t *kd, int n, int i, struct ktr_entry *entry, u_int64_t *last_timestamp); 102 static struct ktr_info *kvm_ktrinfo(kvm_t *kd, void *kptr); 103 static const char *kvm_string(kvm_t *kd, const char *kptr); 104 static const char *trunc_path(const char *str, int maxlen); 105 static void read_symbols(const char *execfile); 106 static const char *address_to_symbol(void *kptr); 107 static struct ktr_buffer *ktr_bufs_init(int); 108 static void load_bufs(struct ktr_buffer *, struct ktr_entry **); 109 static void print_buf(FILE *, struct ktr_buffer *, int, u_int64_t *); 110 static void print_bufs_timesorted(FILE *, struct ktr_buffer *, u_int64_t *); 111 112 113 /* 114 * Reads the ktr trace buffer from kernel memory and prints the trace entries. 115 */ 116 int 117 main(int ac, char **av) 118 { 119 struct ktr_buffer *ktr_bufs; 120 struct ktr_entry **ktr_kbuf; 121 FILE *fo; 122 int64_t tts; 123 int *ktr_start_index; 124 int version; 125 int c; 126 int n; 127 128 /* 129 * Parse commandline arguments. 130 */ 131 fo = stdout; 132 while ((c = getopt(ac, av, "acfinqrtxpslA:N:M:o:")) != -1) { 133 switch (c) { 134 case 'a': 135 cflag = 1; 136 iflag = 1; 137 rflag = 1; 138 xflag = 1; 139 pflag = 1; 140 rflag = 1; 141 sflag = 1; 142 break; 143 case 'c': 144 cflag = 1; 145 break; 146 case 'N': 147 if (strlcpy(execfile, optarg, sizeof(execfile)) 148 >= sizeof(execfile)) 149 errx(1, "%s: File name too long", optarg); 150 Nflag = 1; 151 break; 152 case 'f': 153 fflag = 1; 154 break; 155 case 'l': 156 lflag = 1; 157 break; 158 case 'i': 159 iflag = 1; 160 break; 161 case 'A': 162 correction_factor = strtod(optarg, NULL); 163 break; 164 case 'M': 165 if (strlcpy(corefile, optarg, sizeof(corefile)) 166 >= sizeof(corefile)) 167 errx(1, "%s: File name too long", optarg); 168 Mflag = 1; 169 break; 170 case 'n': 171 nflag = 1; 172 break; 173 case 'o': 174 if ((fo = fopen(optarg, "w")) == NULL) 175 err(1, "%s", optarg); 176 break; 177 case 'p': 178 pflag++; 179 break; 180 case 'q': 181 qflag++; 182 break; 183 case 'r': 184 rflag = 1; 185 break; 186 case 's': 187 sflag = 1; /* sort across the cpus */ 188 break; 189 case 't': 190 tflag = 1; 191 break; 192 case 'x': 193 xflag = 1; 194 break; 195 case '?': 196 default: 197 usage(); 198 } 199 } 200 if (cflag + iflag + tflag + xflag + fflag + pflag == 0) { 201 cflag = 1; 202 iflag = 1; 203 tflag = 1; 204 pflag = 1; 205 } 206 if (correction_factor != 0.0 && (rflag == 0 || nflag)) { 207 fprintf(stderr, "Correction factor can only be applied with -r and without -n\n"); 208 exit(1); 209 } 210 ac -= optind; 211 av += optind; 212 if (ac != 0) 213 usage(); 214 215 /* 216 * Open our execfile and corefile, resolve needed symbols and read in 217 * the trace buffer. 218 */ 219 if ((kd = kvm_openfiles(Nflag ? execfile : NULL, 220 Mflag ? corefile : NULL, NULL, O_RDONLY, errbuf)) == NULL) 221 errx(1, "%s", errbuf); 222 if (kvm_nlist(kd, nl) != 0) 223 errx(1, "%s", kvm_geterr(kd)); 224 if (kvm_read(kd, nl[0].n_value, &version, sizeof(version)) == -1) 225 errx(1, "%s", kvm_geterr(kd)); 226 if (kvm_read(kd, nl[4].n_value, &ncpus, sizeof(ncpus)) == -1) 227 errx(1, "%s", kvm_geterr(kd)); 228 ktr_start_index = malloc(sizeof(*ktr_start_index) * ncpus); 229 if (version >= 3) { 230 if (kvm_read(kd, nl[5].n_value, &tts, sizeof(tts)) == -1) 231 errx(1, "%s", kvm_geterr(kd)); 232 tsc_frequency = (double)tts; 233 } 234 if (version > KTR_VERSION) 235 errx(1, "ktr version too high for us to handle"); 236 if (kvm_read(kd, nl[1].n_value, &entries_per_buf, 237 sizeof(entries_per_buf)) == -1) 238 errx(1, "%s", kvm_geterr(kd)); 239 fifo_mask = entries_per_buf - 1; 240 241 printf("TSC frequency is %6.3f MHz\n", tsc_frequency / 1000000.0); 242 243 ktr_kbuf = malloc(sizeof(*ktr_kbuf) * ncpus); 244 245 if (nflag == 0) 246 read_symbols(Nflag ? execfile : NULL); 247 248 if (kvm_read(kd, nl[3].n_value, ktr_kbuf, sizeof(*ktr_kbuf) * ncpus) == -1) 249 errx(1, "%s", kvm_geterr(kd)); 250 251 ktr_bufs = ktr_bufs_init(ncpus); 252 253 if (sflag) { 254 u_int64_t last_timestamp = 0; 255 do { 256 load_bufs(ktr_bufs, ktr_kbuf); 257 print_bufs_timesorted(fo, ktr_bufs, &last_timestamp); 258 if (lflag) 259 usleep(1000000 / 10); 260 } while (lflag); 261 } else { 262 u_int64_t *last_timestamp = calloc(sizeof(u_int64_t), ncpus); 263 do { 264 load_bufs(ktr_bufs, ktr_kbuf); 265 for (n = 0; n < ncpus; ++n) 266 print_buf(fo, ktr_bufs, n, &last_timestamp[n]); 267 if (lflag) 268 usleep(1000000 / 10); 269 } while (lflag); 270 } 271 return (0); 272 } 273 274 static void 275 print_header(FILE *fo, int row) 276 { 277 if (qflag == 0 && (u_int32_t)row % 20 == 0) { 278 fprintf(fo, "%-6s ", "index"); 279 if (cflag) 280 fprintf(fo, "%-3s ", "cpu"); 281 if (tflag || rflag) 282 fprintf(fo, "%-16s ", "timestamp"); 283 if (xflag) { 284 if (nflag) 285 fprintf(fo, "%-10s %-10s", "caller2", "caller1"); 286 else 287 fprintf(fo, "%-20s %-20s", "caller2", "caller1"); 288 } 289 if (iflag) 290 fprintf(fo, "%-20s ", "ID"); 291 if (fflag) 292 fprintf(fo, "%10s%-30s ", "", "file and line"); 293 if (pflag) 294 fprintf(fo, "%s", "trace"); 295 fprintf(fo, "\n"); 296 } 297 } 298 299 static void 300 print_entry(FILE *fo, kvm_t *kd, int n, int row, struct ktr_entry *entry, 301 u_int64_t *last_timestamp) 302 { 303 struct ktr_info *info = NULL; 304 305 fprintf(fo, " %06x ", row & 0x00FFFFFF); 306 if (cflag) 307 fprintf(fo, "%-3d ", n); 308 if (tflag || rflag) { 309 if (rflag && !nflag && tsc_frequency != 0.0) { 310 fprintf(fo, "%13.3f uS ", 311 (double)(entry->ktr_timestamp - *last_timestamp) * 1000000.0 / tsc_frequency - correction_factor); 312 } else if (rflag) { 313 fprintf(fo, "%-16lld ", entry->ktr_timestamp - 314 *last_timestamp); 315 } else { 316 fprintf(fo, "%-16lld ", entry->ktr_timestamp); 317 } 318 } 319 if (xflag) { 320 if (nflag) { 321 fprintf(fo, "%p %p ", 322 entry->ktr_caller2, entry->ktr_caller1); 323 } else { 324 fprintf(fo, "%-20s ", 325 address_to_symbol(entry->ktr_caller2)); 326 fprintf(fo, "%-20s ", 327 address_to_symbol(entry->ktr_caller1)); 328 } 329 } 330 if (iflag) { 331 info = kvm_ktrinfo(kd, entry->ktr_info); 332 if (info) 333 fprintf(fo, "%-20s ", kvm_string(kd, info->kf_name)); 334 else 335 fprintf(fo, "%-20s ", "<empty>"); 336 } 337 if (fflag) 338 fprintf(fo, "%34s:%-4d ", trunc_path(kvm_string(kd, entry->ktr_file), 34), entry->ktr_line); 339 if (pflag) { 340 if (info == NULL) 341 info = kvm_ktrinfo(kd, entry->ktr_info); 342 if (info) { 343 fprintf(fo, kvm_string(kd, info->kf_format), 344 entry->ktr_data[0], entry->ktr_data[1], 345 entry->ktr_data[2], entry->ktr_data[3], 346 entry->ktr_data[4], entry->ktr_data[5], 347 entry->ktr_data[6], entry->ktr_data[7], 348 entry->ktr_data[8], entry->ktr_data[9]); 349 } else { 350 fprintf(fo, ""); 351 } 352 } 353 fprintf(fo, "\n"); 354 *last_timestamp = entry->ktr_timestamp; 355 } 356 357 static 358 struct ktr_info * 359 kvm_ktrinfo(kvm_t *kd, 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(kvm_t *kd, const char *kptr) 379 { 380 static char save_str[128]; 381 static const char *save_kptr; 382 int l; 383 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 *execfile) 437 { 438 char buf[256]; 439 char cmd[256]; 440 int 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 (execfile == NULL) { 450 if (sysctlbyname("kern.bootfile", buf, &buflen, NULL, 0) < 0) 451 execfile = "/kernel"; 452 else 453 execfile = buf; 454 } 455 snprintf(cmd, sizeof(cmd), "nm -n %s", execfile); 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(int ncpus) 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(kvm_t *kd, 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(kd, 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 int first, last; 614 struct ktr_buffer *buf = ktr_bufs + cpu; 615 616 if (buf->modified == 0) 617 return; 618 if (*last_timestamp == 0) { 619 *last_timestamp = 620 buf->ents[buf->beg_idx & fifo_mask].ktr_timestamp; 621 } 622 while (buf->beg_idx != buf->end_idx) { 623 print_header(fo, buf->beg_idx); 624 print_entry(fo, kd, cpu, buf->beg_idx, 625 &buf->ents[buf->beg_idx & fifo_mask], 626 last_timestamp); 627 ++buf->beg_idx; 628 } 629 buf->modified = 0; 630 } 631 632 static 633 void 634 print_bufs_timesorted(FILE *fo, struct ktr_buffer *ktr_bufs, 635 u_int64_t *last_timestamp) 636 { 637 struct ktr_entry *ent; 638 struct ktr_buffer *buf; 639 int n, bestn; 640 u_int64_t ts; 641 static int row = 0; 642 643 for (;;) { 644 ts = 0; 645 bestn = -1; 646 for (n = 0; n < ncpus; ++n) { 647 buf = ktr_bufs + n; 648 if (buf->beg_idx == buf->end_idx) 649 continue; 650 ent = &buf->ents[buf->beg_idx & fifo_mask]; 651 if (ts == 0 || (ts >= ent->ktr_timestamp)) { 652 ts = ent->ktr_timestamp; 653 bestn = n; 654 } 655 } 656 if ((bestn < 0) || (ts < *last_timestamp)) 657 break; 658 buf = ktr_bufs + bestn; 659 print_header(fo, row); 660 print_entry(fo, kd, bestn, row, 661 &buf->ents[buf->beg_idx & fifo_mask], 662 last_timestamp); 663 ++buf->beg_idx; 664 *last_timestamp = ts; 665 ++row; 666 } 667 } 668 669 static void 670 usage(void) 671 { 672 fprintf(stderr, "usage: ktrdump [-acfilnpqrtx] [-N execfile] " 673 "[-M corefile] [-o outfile]\n"); 674 exit(1); 675 } 676