d81d7f901d91b56bb86e28871064be57ebdad01e
[dragonfly.git] / usr.bin / ktrdump / ktrdump.c
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 }