2 * Copyright (c) 2002 Jake Burkholder
3 * Copyright (c) 2004 Robert Watson
6 * Redistribution and use in source and binary forms, with or without
7 * modification, are permitted provided that the following conditions
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.
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
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 $
31 #include <sys/cdefs.h>
33 #include <sys/types.h>
37 #include <sys/queue.h>
55 struct ktr_entry *ents;
58 int beg_idx; /* Beginning index */
59 int end_idx; /* Ending index */
62 static struct nlist nl1[] = {
63 { .n_name = "_ktr_version" },
64 { .n_name = "_ktr_entries" },
65 { .n_name = "_ncpus" },
69 static struct nlist nl2[] = {
70 { .n_name = "_tsc_frequency" },
74 static struct nlist nl_version_ktr_idx[] = {
75 { .n_name = "_ktr_idx" },
76 { .n_name = "_ktr_buf" },
80 static struct nlist nl_version_ktr_cpu[] = {
81 { .n_name = "_ktr_cpu" },
87 const void *save_kptr;
90 typedef void (*ktr_iter_cb_t)(void *, int, int, struct ktr_entry *, uint64_t *);
106 static double tsc_frequency;
107 static double correction_factor = 0.0;
109 static char corefile[PATH_MAX];
110 static char execfile[PATH_MAX];
112 static char errbuf[_POSIX2_LINE_MAX];
115 static int entries_per_buf;
116 static int fifo_mask;
117 static int ktr_version;
119 static void usage(void);
120 static int earliest_ts(struct ktr_buffer *);
121 static void dump_machine_info(evtr_t);
122 static void dump_device_info(evtr_t);
123 static void print_header(FILE *, int);
124 static void print_entry(FILE *, int, int, struct ktr_entry *, u_int64_t *);
125 static void print_callback(void *, int, int, struct ktr_entry *, uint64_t *);
126 static void dump_callback(void *, int, int, struct ktr_entry *, uint64_t *);
127 static struct ktr_info *kvm_ktrinfo(void *, struct save_ctx *);
128 static const char *kvm_string(const char *, struct save_ctx *);
129 static const char *trunc_path(const char *, int);
130 static void read_symbols(const char *);
131 static const char *address_to_symbol(void *, struct save_ctx *);
132 static struct ktr_buffer *ktr_bufs_init(void);
133 static void get_indices(struct ktr_entry **, int *);
134 static void load_bufs(struct ktr_buffer *, struct ktr_entry **, int *);
135 static void iterate_buf(FILE *, struct ktr_buffer *, int, u_int64_t *, ktr_iter_cb_t);
136 static void iterate_bufs_timesorted(FILE *, struct ktr_buffer *, u_int64_t *, ktr_iter_cb_t);
137 static void kvmfprintf(FILE *fp, const char *ctl, va_list va);
140 * Reads the ktr trace buffer from kernel memory and prints the trace entries.
143 main(int ac, char **av)
145 struct ktr_buffer *ktr_bufs;
146 struct ktr_entry **ktr_kbuf;
147 ktr_iter_cb_t callback = &print_callback;
152 int *ktr_start_index;
157 * Parse commandline arguments.
160 while ((c = getopt(ac, av, "acfinqrtxpslA:N:M:o:d")) != -1) {
176 callback = &dump_callback;
179 if (strlcpy(execfile, optarg, sizeof(execfile))
181 errx(1, "%s: File name too long", optarg);
194 correction_factor = strtod(optarg, NULL);
197 if (strlcpy(corefile, optarg, sizeof(corefile))
199 errx(1, "%s: File name too long", optarg);
206 if ((fo = fopen(optarg, "w")) == NULL)
207 err(1, "%s", optarg);
219 sflag = 1; /* sort across the cpus */
234 ctx = evtr_open_write(fo);
236 err(1, "Can't create event stream");
239 if (cflag + iflag + tflag + xflag + fflag + pflag == 0) {
245 if (correction_factor != 0.0 && (rflag == 0 || nflag)) {
246 fprintf(stderr, "Correction factor can only be applied with -r and without -n\n");
255 * Open our execfile and corefile, resolve needed symbols and read in
258 if ((kd = kvm_openfiles(Nflag ? execfile : NULL,
259 Mflag ? corefile : NULL, NULL, O_RDONLY, errbuf)) == NULL)
260 errx(1, "%s", errbuf);
261 if (kvm_nlist(kd, nl1) != 0)
262 errx(1, "%s", kvm_geterr(kd));
263 if (kvm_read(kd, nl1[0].n_value, &ktr_version, sizeof(ktr_version)) == -1)
264 errx(1, "%s", kvm_geterr(kd));
265 if (kvm_read(kd, nl1[2].n_value, &ncpus, sizeof(ncpus)) == -1)
266 errx(1, "%s", kvm_geterr(kd));
267 ktr_start_index = malloc(sizeof(*ktr_start_index) * ncpus);
268 if (ktr_version >= KTR_VERSION_WITH_FREQ && kvm_nlist(kd, nl2) == 0) {
269 if (kvm_read(kd, nl2[0].n_value, &tts, sizeof(tts)) == -1)
270 errx(1, "%s", kvm_geterr(kd));
271 tsc_frequency = (double)tts;
273 if (ktr_version > KTR_VERSION)
274 errx(1, "ktr version too high for us to handle");
275 if (kvm_read(kd, nl1[1].n_value, &entries_per_buf,
276 sizeof(entries_per_buf)) == -1)
277 errx(1, "%s", kvm_geterr(kd));
278 fifo_mask = entries_per_buf - 1;
280 printf("TSC frequency is %6.3f MHz\n", tsc_frequency / 1000000.0);
283 dump_machine_info((evtr_t)ctx);
284 dump_device_info((evtr_t)ctx);
286 ktr_kbuf = calloc(ncpus, sizeof(*ktr_kbuf));
287 ktr_idx = calloc(ncpus, sizeof(*ktr_idx));
290 read_symbols(Nflag ? execfile : NULL);
292 if (ktr_version < KTR_VERSION_KTR_CPU) {
293 if (kvm_nlist(kd, nl_version_ktr_idx))
294 errx(1, "%s", kvm_geterr(kd));
296 if (kvm_nlist(kd, nl_version_ktr_cpu))
297 errx(1, "%s", kvm_geterr(kd));
300 get_indices(ktr_kbuf, ktr_idx);
302 ktr_bufs = ktr_bufs_init();
305 u_int64_t last_timestamp = 0;
307 load_bufs(ktr_bufs, ktr_kbuf, ktr_idx);
308 iterate_bufs_timesorted(ctx, ktr_bufs, &last_timestamp,
311 usleep(1000000 / 10);
314 u_int64_t *last_timestamp = calloc(sizeof(u_int64_t), ncpus);
316 load_bufs(ktr_bufs, ktr_kbuf, ktr_idx);
317 for (n = 0; n < ncpus; ++n)
318 iterate_buf(ctx, ktr_bufs, n, &last_timestamp[n],
321 usleep(1000000 / 10);
331 dump_devinfo(struct devinfo_dev *dev, void *arg)
333 struct evtr_event ev;
334 evtr_t evtr = (evtr_t)arg;
335 const char *fmt = "#devicenames[\"%s\"] = %#lx";
336 char fmtdatabuf[sizeof(char *) + sizeof(devinfo_handle_t)];
337 char *fmtdata = fmtdatabuf;
339 if (!dev->dd_name[0])
341 ev.type = EVTR_TYPE_PROBE;
348 ((char **)fmtdata)[0] = &dev->dd_name[0];
349 fmtdata += sizeof(char *);
350 ((devinfo_handle_t *)fmtdata)[0] = dev->dd_handle;
351 ev.fmtdata = fmtdatabuf;
352 ev.fmtdatalen = sizeof(fmtdatabuf);
354 if (evtr_dump_event(evtr, &ev)) {
355 err(1, evtr_errmsg(evtr));
358 return devinfo_foreach_device_child(dev, dump_devinfo, evtr);
363 dump_device_info(evtr_t evtr)
365 struct devinfo_dev *root;
368 if (!(root = devinfo_handle_to_device(DEVINFO_ROOT_DEVICE))) {
369 warn("can't find root device");
372 devinfo_foreach_device_child(root, dump_devinfo, evtr);
377 dump_machine_info(evtr_t evtr)
379 struct evtr_event ev;
382 bzero(&ev, sizeof(ev));
383 ev.type = EVTR_TYPE_SYSINFO;
385 evtr_dump_event(evtr, &ev);
386 if (evtr_error(evtr)) {
387 err(1, evtr_errmsg(evtr));
390 for (i = 0; i < ncpus; ++i) {
391 bzero(&ev, sizeof(ev));
392 ev.type = EVTR_TYPE_CPUINFO;
394 ev.cpuinfo.freq = tsc_frequency;
395 evtr_dump_event(evtr, &ev);
396 if (evtr_error(evtr)) {
397 err(1, evtr_errmsg(evtr));
403 print_header(FILE *fo, int row)
405 if (qflag == 0 && (u_int32_t)row % 20 == 0) {
406 fprintf(fo, "%-6s ", "index");
408 fprintf(fo, "%-3s ", "cpu");
410 fprintf(fo, "%-16s ", "timestamp");
413 fprintf(fo, "%-10s %-10s", "caller2", "caller1");
415 fprintf(fo, "%-20s %-20s", "caller2", "caller1");
418 fprintf(fo, "%-20s ", "ID");
420 fprintf(fo, "%10s%-30s ", "", "file and line");
422 fprintf(fo, "%s", "trace");
428 print_entry(FILE *fo, int n, int row, struct ktr_entry *entry,
429 u_int64_t *last_timestamp)
431 struct ktr_info *info = NULL;
432 static struct save_ctx nctx, pctx, fmtctx, symctx, infoctx;
434 fprintf(fo, " %06x ", row & 0x00FFFFFF);
436 fprintf(fo, "%-3d ", n);
437 if (tflag || rflag) {
438 if (rflag && !nflag && tsc_frequency != 0.0) {
439 fprintf(fo, "%13.3f uS ",
440 (double)(entry->ktr_timestamp - *last_timestamp) * 1000000.0 / tsc_frequency - correction_factor);
442 fprintf(fo, "%-16ju ",
443 (uintmax_t)(entry->ktr_timestamp - *last_timestamp));
445 fprintf(fo, "%-16ju ",
446 (uintmax_t)entry->ktr_timestamp);
451 fprintf(fo, "%p %p ",
452 entry->ktr_caller2, entry->ktr_caller1);
454 fprintf(fo, "%-25s ",
455 address_to_symbol(entry->ktr_caller2, &symctx));
456 fprintf(fo, "%-25s ",
457 address_to_symbol(entry->ktr_caller1, &symctx));
461 info = kvm_ktrinfo(entry->ktr_info, &infoctx);
463 fprintf(fo, "%-20s ", kvm_string(info->kf_name, &nctx));
465 fprintf(fo, "%-20s ", "<empty>");
468 fprintf(fo, "%34s:%-4d ",
469 trunc_path(kvm_string(entry->ktr_file, &pctx), 34),
473 info = kvm_ktrinfo(entry->ktr_info, &infoctx);
475 kvmfprintf(fo, kvm_string(info->kf_format, &fmtctx),
476 (void *)&entry->ktr_data);
479 *last_timestamp = entry->ktr_timestamp;
484 print_callback(void *ctx, int n, int row, struct ktr_entry *entry, uint64_t *last_ts)
486 FILE *fo = (FILE *)ctx;
487 print_header(fo, row);
488 print_entry(fo, n, row, entry, last_ts);
492 * If free == 0, replace all (kvm) string pointers in fmtdata with pointers
493 * to user-allocated copies of the strings.
494 * If free != 0, free those pointers.
498 mangle_string_ptrs(const char *fmt, uint8_t *fmtdata, int dofree)
501 size_t skipsize, intsz;
502 static struct save_ctx strctx;
505 for (f = fmt; f[0] != '\0'; ++f) {
510 for (p = f; p[0]; ++p) {
513 * Eat flags. Notice this will accept duplicate
529 /* Eat minimum field width, if any */
530 for (; isdigit(p[0]); ++p)
534 /* Eat precision, if any */
535 for (; isdigit(p[0]); ++p)
542 intsz = sizeof(long long);
544 intsz = sizeof(long);
548 intsz = sizeof(intmax_t);
551 intsz = sizeof(ptrdiff_t);
554 intsz = sizeof(size_t);
575 skipsize = sizeof(void *);
579 skipsize = sizeof(double);
581 skipsize = sizeof(float);
585 char *t = ((char **)fmtdata)[0];
587 skipsize = sizeof(char *);
589 char *t = strdup(kvm_string(((char **)fmtdata)[0],
591 ((const char **)fmtdata)[0] = t;
593 skipsize = sizeof(char *);
598 fprintf(stderr, "Unknown conversion specifier %c "
599 "in fmt starting with %s", p[0], f - 1);
609 dump_callback(void *ctx, int n, int row __unused, struct ktr_entry *entry,
610 uint64_t *last_ts __unused)
612 evtr_t evtr = (evtr_t)ctx;
613 struct evtr_event ev;
614 static struct save_ctx pctx, fmtctx, infoctx;
616 int conv = 0; /* pointless */
618 ev.ts = entry->ktr_timestamp;
619 ev.type = EVTR_TYPE_PROBE;
620 ev.line = entry->ktr_line;
621 ev.file = kvm_string(entry->ktr_file, &pctx);
624 if ((ki = kvm_ktrinfo(entry->ktr_info, &infoctx))) {
625 ev.fmt = kvm_string(ki->kf_format, &fmtctx);
626 ev.fmtdata = entry->ktr_data;
627 if ((conv = mangle_string_ptrs(ev.fmt,
628 __DECONST(uint8_t *, ev.fmtdata),
630 errx(1, "Can't parse format string\n");
631 ev.fmtdatalen = ki->kf_data_size;
633 ev.fmt = ev.fmtdata = NULL;
636 if (evtr_dump_event(evtr, &ev)) {
637 err(1, evtr_errmsg(evtr));
639 if (ev.fmtdata && conv) {
640 mangle_string_ptrs(ev.fmt, __DECONST(uint8_t *, ev.fmtdata),
647 kvm_ktrinfo(void *kptr, struct save_ctx *ctx)
649 struct ktr_info *ki = (void *)ctx->save_buf;
653 if (ctx->save_kptr != kptr) {
654 if (kvm_read(kd, (uintptr_t)kptr, ki, sizeof(*ki)) == -1) {
655 bzero(&ki, sizeof(*ki));
657 ctx->save_kptr = kptr;
665 kvm_string(const char *kptr, struct save_ctx *ctx)
672 if (ctx->save_kptr != (const void *)kptr) {
673 ctx->save_kptr = (const void *)kptr;
675 while (l < sizeof(ctx->save_buf) - 1) {
676 n = 256 - ((intptr_t)(kptr + l) & 255);
677 if (n > sizeof(ctx->save_buf) - l - 1)
678 n = sizeof(ctx->save_buf) - l - 1;
679 if (kvm_read(kd, (uintptr_t)(kptr + l), ctx->save_buf + l, n) < 0)
681 while (l < sizeof(ctx->save_buf) && n) {
682 if (ctx->save_buf[l] == 0)
690 ctx->save_buf[l] = 0;
692 return(ctx->save_buf);
697 trunc_path(const char *str, int maxlen)
699 int len = strlen(str);
702 return(str + len - maxlen);
708 TAILQ_ENTRY(symdata) link;
714 static TAILQ_HEAD(symlist, symdata) symlist;
715 static struct symdata *symcache;
716 static char *symbegin;
721 read_symbols(const char *file)
725 size_t buflen = sizeof(buf);
732 TAILQ_INIT(&symlist);
735 if (sysctlbyname("kern.bootfile", buf, &buflen, NULL, 0) < 0)
736 file = "/boot/kernel";
740 snprintf(cmd, sizeof(cmd), "nm -n %s", file);
741 if ((fp = popen(cmd, "r")) != NULL) {
742 while (fgets(buf, sizeof(buf), fp) != NULL) {
743 s1 = strtok(buf, " \t\n");
744 s2 = strtok(NULL, " \t\n");
745 s3 = strtok(NULL, " \t\n");
746 if (s1 && s2 && s3) {
747 sym = malloc(sizeof(struct symdata));
748 sym->symaddr = (char *)strtoul(s1, NULL, 16);
749 sym->symtype = s2[0];
750 sym->symname = strdup(s3);
751 if (strcmp(s3, "kernbase") == 0)
752 symbegin = sym->symaddr;
753 if (strcmp(s3, "end") == 0)
754 symend = sym->symaddr;
755 TAILQ_INSERT_TAIL(&symlist, sym, link);
760 symcache = TAILQ_FIRST(&symlist);
765 address_to_symbol(void *kptr, struct save_ctx *ctx)
767 char *buf = ctx->save_buf;
768 int size = sizeof(ctx->save_buf);
770 if (symcache == NULL ||
771 (char *)kptr < symbegin || (char *)kptr >= symend
773 snprintf(buf, size, "%p", kptr);
776 while ((char *)symcache->symaddr < (char *)kptr) {
777 if (TAILQ_NEXT(symcache, link) == NULL)
779 symcache = TAILQ_NEXT(symcache, link);
781 while ((char *)symcache->symaddr > (char *)kptr) {
782 if (symcache != TAILQ_FIRST(&symlist))
783 symcache = TAILQ_PREV(symcache, symlist, link);
785 snprintf(buf, size, "%s+%d", symcache->symname,
786 (int)((char *)kptr - symcache->symaddr));
794 struct ktr_buffer *ktr_bufs, *it;
797 ktr_bufs = malloc(sizeof(*ktr_bufs) * ncpus);
799 err(1, "can't allocate data structures\n");
800 for (i = 0; i < ncpus; ++i) {
802 it->ents = malloc(sizeof(struct ktr_entry) * entries_per_buf);
803 if (it->ents == NULL)
804 err(1, "can't allocate data structures\n");
814 get_indices(struct ktr_entry **ktr_kbuf, int *ktr_idx)
816 static struct ktr_cpu *ktr_cpus;
819 if (ktr_cpus == NULL)
820 ktr_cpus = malloc(sizeof(*ktr_cpus) * ncpus);
822 if (ktr_version < KTR_VERSION_KTR_CPU) {
823 if (kvm_read(kd, nl_version_ktr_idx[0].n_value, ktr_idx,
824 sizeof(*ktr_idx) * ncpus) == -1) {
825 errx(1, "%s", kvm_geterr(kd));
827 if (ktr_kbuf[0] == NULL) {
828 if (kvm_read(kd, nl_version_ktr_idx[1].n_value,
829 ktr_kbuf, sizeof(*ktr_kbuf) * ncpus) == -1) {
830 errx(1, "%s", kvm_geterr(kd));
834 if (kvm_read(kd, nl_version_ktr_cpu[0].n_value,
835 ktr_cpus, sizeof(*ktr_cpus) * ncpus) == -1) {
836 errx(1, "%s", kvm_geterr(kd));
838 for (i = 0; i < ncpus; ++i) {
839 ktr_idx[i] = ktr_cpus[i].core.ktr_idx;
840 ktr_kbuf[i] = ktr_cpus[i].core.ktr_buf;
846 * Get the trace buffer data from the kernel
850 load_bufs(struct ktr_buffer *ktr_bufs, struct ktr_entry **kbufs, int *ktr_idx)
852 struct ktr_buffer *kbuf;
855 get_indices(kbufs, ktr_idx);
856 for (i = 0; i < ncpus; ++i) {
858 if (ktr_idx[i] == kbuf->end_idx)
860 kbuf->end_idx = ktr_idx[i];
863 * If we do not have a notion of the beginning index, assume
864 * it is entries_per_buf before the ending index. Don't
865 * worry about underflows/negative numbers, the indices will
869 kbuf->beg_idx = kbuf->end_idx - entries_per_buf + 1;
872 if (kvm_read(kd, (uintptr_t)kbufs[i], ktr_bufs[i].ents,
873 sizeof(struct ktr_entry) * entries_per_buf)
875 errx(1, "%s", kvm_geterr(kd));
877 kbuf->beg_idx = earliest_ts(kbuf);
883 * Locate the earliest timestamp iterating backwards from end_idx, but
884 * not going further back then beg_idx. We have to do this because
885 * the kernel uses a circulating buffer.
889 earliest_ts(struct ktr_buffer *buf)
891 struct ktr_entry *save;
892 int count, scan, i, earliest;
895 earliest = buf->end_idx - 1;
896 save = &buf->ents[earliest & fifo_mask];
897 for (scan = buf->end_idx - 1; scan != buf->beg_idx -1; --scan) {
898 i = scan & fifo_mask;
899 if (buf->ents[i].ktr_timestamp <= save->ktr_timestamp &&
900 buf->ents[i].ktr_timestamp > 0)
903 * We may have gotten so far behind that beg_idx wrapped
904 * more then once around the buffer. Just stop
906 if (++count == entries_per_buf)
914 iterate_buf(FILE *fo, struct ktr_buffer *ktr_bufs, int cpu,
915 u_int64_t *last_timestamp, ktr_iter_cb_t cb)
917 struct ktr_buffer *buf = ktr_bufs + cpu;
919 if (buf->modified == 0)
921 if (*last_timestamp == 0) {
923 buf->ents[buf->beg_idx & fifo_mask].ktr_timestamp;
925 while (buf->beg_idx != buf->end_idx) {
926 cb(fo, cpu, buf->beg_idx,
927 &buf->ents[buf->beg_idx & fifo_mask],
936 iterate_bufs_timesorted(FILE *fo, struct ktr_buffer *ktr_bufs,
937 u_int64_t *last_timestamp, ktr_iter_cb_t cb)
939 struct ktr_entry *ent;
940 struct ktr_buffer *buf;
948 for (n = 0; n < ncpus; ++n) {
950 if (buf->beg_idx == buf->end_idx)
952 ent = &buf->ents[buf->beg_idx & fifo_mask];
953 if (ts == 0 || (ts >= ent->ktr_timestamp)) {
954 ts = ent->ktr_timestamp;
958 if ((bestn < 0) || (ts < *last_timestamp))
960 buf = ktr_bufs + bestn;
962 &buf->ents[buf->beg_idx & fifo_mask],
965 *last_timestamp = ts;
972 kvmfprintf(FILE *fp, const char *ctl, va_list va)
978 static struct save_ctx strctx;
982 for (n = 0; ctl[n]; ++n) {
991 while (n < (int)sizeof(fmt)) {
1018 va_arg(va, long long));
1022 va_arg(va, size_t));
1032 s = kvm_string(va_arg(va, char *), &strctx);
1033 fwrite(s, 1, strlen(s), fp);
1042 va_arg(va, double));
1078 fprintf(fp, fmt, NULL);
1087 fprintf(stderr, "usage: ktrdump [-acfilnpqrstx] [-A factor] "
1088 "[-N execfile] [-M corefile] [-o outfile]\n");