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 vfprintf(fo, kvm_string(info->kf_format), (void *)&entry->ktr_data); 346 } 347 fprintf(fo, "\n"); 348 *last_timestamp = entry->ktr_timestamp; 349 } 350 351 static 352 struct ktr_info * 353 kvm_ktrinfo(void *kptr) 354 { 355 static struct ktr_info save_info; 356 static void *save_kptr; 357 358 if (kptr == NULL) 359 return(NULL); 360 if (save_kptr != kptr) { 361 if (kvm_read(kd, (uintptr_t)kptr, &save_info, sizeof(save_info)) == -1) { 362 bzero(&save_info, sizeof(save_info)); 363 } else { 364 save_kptr = kptr; 365 } 366 } 367 return(&save_info); 368 } 369 370 static 371 const char * 372 kvm_string(const char *kptr) 373 { 374 static char save_str[128]; 375 static const char *save_kptr; 376 u_int l; 377 u_int n; 378 379 if (kptr == NULL) 380 return("?"); 381 if (save_kptr != kptr) { 382 save_kptr = kptr; 383 l = 0; 384 while (l < sizeof(save_str) - 1) { 385 n = 256 - ((intptr_t)(kptr + l) & 255); 386 if (n > sizeof(save_str) - l - 1) 387 n = sizeof(save_str) - l - 1; 388 if (kvm_read(kd, (uintptr_t)(kptr + l), save_str + l, n) < 0) 389 break; 390 while (l < sizeof(save_str) && n) { 391 if (save_str[l] == 0) 392 break; 393 --n; 394 ++l; 395 } 396 if (n) 397 break; 398 } 399 save_str[l] = 0; 400 } 401 return(save_str); 402 } 403 404 static 405 const char * 406 trunc_path(const char *str, int maxlen) 407 { 408 int len = strlen(str); 409 410 if (len > maxlen) 411 return(str + len - maxlen); 412 else 413 return(str); 414 } 415 416 struct symdata { 417 TAILQ_ENTRY(symdata) link; 418 const char *symname; 419 char *symaddr; 420 char symtype; 421 }; 422 423 static TAILQ_HEAD(symlist, symdata) symlist; 424 static struct symdata *symcache; 425 static char *symbegin; 426 static char *symend; 427 428 static 429 void 430 read_symbols(const char *file) 431 { 432 char buf[256]; 433 char cmd[256]; 434 size_t buflen = sizeof(buf); 435 FILE *fp; 436 struct symdata *sym; 437 char *s1; 438 char *s2; 439 char *s3; 440 441 TAILQ_INIT(&symlist); 442 443 if (file == NULL) { 444 if (sysctlbyname("kern.bootfile", buf, &buflen, NULL, 0) < 0) 445 file = "/boot/kernel"; 446 else 447 file = buf; 448 } 449 snprintf(cmd, sizeof(cmd), "nm -n %s", file); 450 if ((fp = popen(cmd, "r")) != NULL) { 451 while (fgets(buf, sizeof(buf), fp) != NULL) { 452 s1 = strtok(buf, " \t\n"); 453 s2 = strtok(NULL, " \t\n"); 454 s3 = strtok(NULL, " \t\n"); 455 if (s1 && s2 && s3) { 456 sym = malloc(sizeof(struct symdata)); 457 sym->symaddr = (char *)strtoul(s1, NULL, 16); 458 sym->symtype = s2[0]; 459 sym->symname = strdup(s3); 460 if (strcmp(s3, "kernbase") == 0) 461 symbegin = sym->symaddr; 462 if (strcmp(s3, "end") == 0) 463 symend = sym->symaddr; 464 TAILQ_INSERT_TAIL(&symlist, sym, link); 465 } 466 } 467 pclose(fp); 468 } 469 symcache = TAILQ_FIRST(&symlist); 470 } 471 472 static 473 const char * 474 address_to_symbol(void *kptr) 475 { 476 static char buf[64]; 477 478 if (symcache == NULL || 479 (char *)kptr < symbegin || (char *)kptr >= symend 480 ) { 481 snprintf(buf, sizeof(buf), "%p", kptr); 482 return(buf); 483 } 484 while ((char *)symcache->symaddr < (char *)kptr) { 485 if (TAILQ_NEXT(symcache, link) == NULL) 486 break; 487 symcache = TAILQ_NEXT(symcache, link); 488 } 489 while ((char *)symcache->symaddr > (char *)kptr) { 490 if (symcache != TAILQ_FIRST(&symlist)) 491 symcache = TAILQ_PREV(symcache, symlist, link); 492 } 493 snprintf(buf, sizeof(buf), "%s+%d", symcache->symname, 494 (int)((char *)kptr - symcache->symaddr)); 495 return(buf); 496 } 497 498 static 499 struct ktr_buffer * 500 ktr_bufs_init(void) 501 { 502 struct ktr_buffer *ktr_bufs, *it; 503 int i; 504 505 ktr_bufs = malloc(sizeof(*ktr_bufs) * ncpus); 506 if (!ktr_bufs) 507 err(1, "can't allocate data structures\n"); 508 for (i = 0; i < ncpus; ++i) { 509 it = ktr_bufs + i; 510 it->ents = malloc(sizeof(struct ktr_entry) * entries_per_buf); 511 if (it->ents == NULL) 512 err(1, "can't allocate data structures\n"); 513 it->reset = 1; 514 it->beg_idx = -1; 515 it->end_idx = -1; 516 } 517 return ktr_bufs; 518 } 519 520 static 521 void 522 get_indices(int *idx) 523 { 524 if (kvm_read(kd, nl[2].n_value, idx, sizeof(*idx) * ncpus) == -1) 525 errx(1, "%s", kvm_geterr(kd)); 526 } 527 528 /* 529 * Get the trace buffer data from the kernel 530 */ 531 static 532 void 533 load_bufs(struct ktr_buffer *ktr_bufs, struct ktr_entry **kbufs) 534 { 535 static int *kern_idx; 536 struct ktr_buffer *kbuf; 537 int i; 538 539 if (!kern_idx) { 540 kern_idx = malloc(sizeof(*kern_idx) * ncpus); 541 if (!kern_idx) { 542 err(1, "can't allocate data structures\n"); 543 } 544 } 545 546 get_indices(kern_idx); 547 for (i = 0; i < ncpus; ++i) { 548 kbuf = &ktr_bufs[i]; 549 if (kern_idx[i] == kbuf->end_idx) 550 continue; 551 kbuf->end_idx = kern_idx[i]; 552 553 /* 554 * If we do not have a notion of the beginning index, assume 555 * it is entries_per_buf before the ending index. Don't 556 * worry about underflows/negative numbers, the indices will 557 * be masked. 558 */ 559 if (kbuf->reset) { 560 kbuf->beg_idx = kbuf->end_idx - entries_per_buf + 1; 561 kbuf->reset = 0; 562 } 563 if (kvm_read(kd, (uintptr_t)kbufs[i], ktr_bufs[i].ents, 564 sizeof(struct ktr_entry) * entries_per_buf) 565 == -1) 566 errx(1, "%s", kvm_geterr(kd)); 567 kbuf->modified = 1; 568 kbuf->beg_idx = earliest_ts(kbuf); 569 } 570 571 } 572 573 /* 574 * Locate the earliest timestamp iterating backwards from end_idx, but 575 * not going further back then beg_idx. We have to do this because 576 * the kernel uses a circulating buffer. 577 */ 578 static 579 int 580 earliest_ts(struct ktr_buffer *buf) 581 { 582 struct ktr_entry *save; 583 int count, scan, i, earliest; 584 585 count = 0; 586 earliest = buf->end_idx - 1; 587 save = &buf->ents[earliest & fifo_mask]; 588 for (scan = buf->end_idx - 1; scan != buf->beg_idx -1; --scan) { 589 i = scan & fifo_mask; 590 if (buf->ents[i].ktr_timestamp <= save->ktr_timestamp) 591 earliest = scan; 592 /* 593 * We may have gotten so far behind that beg_idx wrapped 594 * more then once around the buffer. Just stop 595 */ 596 if (++count == entries_per_buf) 597 break; 598 } 599 return earliest; 600 } 601 602 static 603 void 604 print_buf(FILE *fo, struct ktr_buffer *ktr_bufs, int cpu, 605 u_int64_t *last_timestamp) 606 { 607 struct ktr_buffer *buf = ktr_bufs + cpu; 608 609 if (buf->modified == 0) 610 return; 611 if (*last_timestamp == 0) { 612 *last_timestamp = 613 buf->ents[buf->beg_idx & fifo_mask].ktr_timestamp; 614 } 615 while (buf->beg_idx != buf->end_idx) { 616 print_header(fo, buf->beg_idx); 617 print_entry(fo, cpu, buf->beg_idx, 618 &buf->ents[buf->beg_idx & fifo_mask], 619 last_timestamp); 620 ++buf->beg_idx; 621 } 622 buf->modified = 0; 623 } 624 625 static 626 void 627 print_bufs_timesorted(FILE *fo, struct ktr_buffer *ktr_bufs, 628 u_int64_t *last_timestamp) 629 { 630 struct ktr_entry *ent; 631 struct ktr_buffer *buf; 632 int n, bestn; 633 u_int64_t ts; 634 static int row = 0; 635 636 for (;;) { 637 ts = 0; 638 bestn = -1; 639 for (n = 0; n < ncpus; ++n) { 640 buf = ktr_bufs + n; 641 if (buf->beg_idx == buf->end_idx) 642 continue; 643 ent = &buf->ents[buf->beg_idx & fifo_mask]; 644 if (ts == 0 || (ts >= ent->ktr_timestamp)) { 645 ts = ent->ktr_timestamp; 646 bestn = n; 647 } 648 } 649 if ((bestn < 0) || (ts < *last_timestamp)) 650 break; 651 buf = ktr_bufs + bestn; 652 print_header(fo, row); 653 print_entry(fo, bestn, row, 654 &buf->ents[buf->beg_idx & fifo_mask], 655 last_timestamp); 656 ++buf->beg_idx; 657 *last_timestamp = ts; 658 ++row; 659 } 660 } 661 662 static void 663 usage(void) 664 { 665 fprintf(stderr, "usage: ktrdump [-acfilnpqrstx] [-A factor] [-N execfile] " 666 "[-M corefile] [-o outfile]\n"); 667 exit(1); 668 } 669