Index: sys/amd64/conf/GENERIC =================================================================== --- sys/amd64/conf/GENERIC (revision 270750) +++ sys/amd64/conf/GENERIC (working copy) @@ -71,6 +71,8 @@ options KDTRACE_HOOKS # Kernel DTrace hooks options DDB_CTF # Kernel ELF linker loads CTF data options INCLUDE_CONFIG_FILE # Include this file in kernel +options KTR +options KTR_COMPILE=(KTR_LOCK|KTR_INTR|KTR_PROC) # Debugging support. Always need this: options KDB # Enable kernel debugger support. Index: sys/kern/kern_ktr.c =================================================================== --- sys/kern/kern_ktr.c (revision 270750) +++ sys/kern/kern_ktr.c (working copy) @@ -88,7 +88,7 @@ #endif #ifndef KTR_CPU -#define KTR_CPU PCPU_GET(cpuid) +#define KTR_CPU curcpu #endif static MALLOC_DEFINE(M_KTR, "KTR", "KTR"); @@ -100,8 +100,13 @@ int ktr_compile = KTR_COMPILE; int ktr_entries = KTR_BOOT_ENTRIES; int ktr_version = KTR_VERSION; -struct ktr_entry ktr_buf_init[KTR_BOOT_ENTRIES]; -struct ktr_entry *ktr_buf = ktr_buf_init; + +/* CPU0 gets a static buffer so that tracing can be used in early boot */ +struct ktr_entry ktr_buf_init[KTR_BOOT_ENTRIES]; +struct ktr_entry *ktr_buf = ktr_buf_init; +struct ktr_pcpu ktr_pcpu_buf[MAXCPU] = { + { .ktr_buf = &ktr_buf_init[0] } +}; cpuset_t ktr_cpumask = CPUSET_T_INITIALIZER(KTR_CPUMASK); static SYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options"); @@ -176,7 +181,6 @@ sysctl_debug_ktr_mask, "IU", "Bitmask of KTR event classes for which logging is enabled"); -#if KTR_ENTRIES > KTR_BOOT_ENTRIES /* * A simplified version of sysctl_debug_ktr_entries. * No need to care about SMP, scheduling, etc. @@ -184,31 +188,48 @@ static void ktr_entries_initializer(void *dummy __unused) { - int mask; + struct ktr_entry *ktr_buf; + int i, idx, mask; - /* Temporarily disable ktr in case malloc() is being traced. */ + /* + * Temporarily disable KTR in case malloc() is being traced. + */ mask = ktr_mask; ktr_mask = 0; + + /* + * For CPU0, we need to copy all the entries traced at early boot + * time in the new buffer. + */ + ktr_buf = ktr_pcpu_buf[0].ktr_buf; + idx = ktr_pcpu_buf[0].ktr_idx; ktr_buf = malloc(sizeof(*ktr_buf) * KTR_ENTRIES, M_KTR, M_WAITOK | M_ZERO); - memcpy(ktr_buf, ktr_buf_init + ktr_idx, - (KTR_BOOT_ENTRIES - ktr_idx) * sizeof(*ktr_buf)); - if (ktr_idx != 0) { - memcpy(ktr_buf + KTR_BOOT_ENTRIES - ktr_idx, ktr_buf_init, + memcpy(ktr_buf, ktr_buf_init + idx, + (KTR_BOOT_ENTRIES - idx) * sizeof(*ktr_buf)); + if (idx != 0) { + memcpy(ktr_buf + KTR_BOOT_ENTRIES - idx, ktr_buf_init, ktr_idx * sizeof(*ktr_buf)); ktr_idx = KTR_BOOT_ENTRIES; } + for (i = 1; i < mp_ncpus; ++i) { + ktr_pcpu_buf[i].ktr_buf = malloc(sizeof(*ktr_buf) * KTR_ENTRIES, + M_KTR, M_WAITOK | M_ZERO); + } + + /* + * Re-enable KTR. + */ ktr_entries = KTR_ENTRIES; ktr_mask = mask; } SYSINIT(ktr_entries_initializer, SI_SUB_KMEM, SI_ORDER_ANY, ktr_entries_initializer, NULL); -#endif static int sysctl_debug_ktr_entries(SYSCTL_HANDLER_ARGS) { - int entries, error, mask; + int entries, error, i, mask; struct ktr_entry *buf, *oldbuf; entries = ktr_entries; @@ -225,20 +246,26 @@ ktr_mask = mask; return (error); } - if (ktr_buf != ktr_buf_init) - oldbuf = ktr_buf; - else - oldbuf = NULL; - /* Allocate a new buffer. */ - buf = malloc(sizeof(*buf) * entries, M_KTR, M_WAITOK | M_ZERO); - /* Install the new buffer and restart ktr. */ - ktr_buf = buf; - ktr_entries = entries; - ktr_idx = 0; + + for (i = 0; i < mp_ncpus; ++i) { + critical_enter(); /* XXXDAVIDE: needed? */ + if (i > 0 || ktr_buf != ktr_buf_init) + oldbuf = ktr_buf; + else + oldbuf = NULL; + + /* Allocate a new buffer. */ + buf = malloc(sizeof(*buf) * entries, M_KTR, M_WAITOK | M_ZERO); + + /* Install the new buffer and restart KTR. */ + ktr_pcpu_buf[i].ktr_buf = buf; + ktr_pcpu_buf[i].ktr_idx = 0; + if (oldbuf != NULL) + free(oldbuf, M_KTR); + critical_exit(); /* XXXDAVIDE: needed? */ + } atomic_store_rel_int(&ktr_mask, mask); - if (oldbuf != NULL) - free(oldbuf, M_KTR); - + ktr_entries = entries; /* XXXDAVIDE: atomic? */ return (error); } @@ -318,19 +345,15 @@ #ifdef KTR_ALQ struct ale *ale = NULL; #endif - int newindex, saveindex; #if defined(KTR_VERBOSE) || defined(KTR_ALQ) struct thread *td; #endif - int cpu; + int cpu, idx; if (panicstr || kdb_active) return; - if ((ktr_mask & mask) == 0 || ktr_buf == NULL) + if ((ktr_mask & mask) == 0) return; - cpu = KTR_CPU; - if (!CPU_ISSET(cpu, &ktr_cpumask)) - return; #if defined(KTR_VERBOSE) || defined(KTR_ALQ) td = curthread; if (td->td_pflags & TDP_INKTR) @@ -355,13 +378,19 @@ } } else #endif - { - do { - saveindex = ktr_idx; - newindex = (saveindex + 1) % ktr_entries; - } while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0); - entry = &ktr_buf[saveindex]; + + /* XXXDAVIDE: critical_enter() in early boot is dangerous? */ + critical_enter(); + cpu = curcpu; + if (ktr_pcpu_buf[cpu].ktr_buf == NULL || + !CPU_ISSET(cpu, &ktr_cpumask)) { + critical_exit(); + return; } + idx = (ktr_pcpu_buf[cpu].ktr_idx + 1) % ktr_entries; + entry = &ktr_pcpu_buf[cpu].ktr_buf[idx]; + ktr_pcpu_buf[cpu].ktr_idx = idx; + critical_exit(); entry->ktr_timestamp = KTR_TIME; entry->ktr_cpu = cpu; entry->ktr_thread = curthread; Index: sys/sys/ktr.h =================================================================== --- sys/sys/ktr.h (revision 270750) +++ sys/sys/ktr.h (working copy) @@ -51,6 +51,12 @@ #include #include +/* XXX: Cache aligned? */ +struct ktr_pcpu { + struct ktr_entry *ktr_buf; + int ktr_idx; +}; + struct ktr_entry { u_int64_t ktr_timestamp; int ktr_cpu; Index: usr.bin/ktrdump/Makefile =================================================================== --- usr.bin/ktrdump/Makefile (revision 270727) +++ usr.bin/ktrdump/Makefile (working copy) @@ -5,6 +5,6 @@ LDADD= -lkvm MAN= ktrdump.8 -WARNS?= 2 +WARNS?= 1 .include Index: usr.bin/ktrdump/ktrdump.c =================================================================== --- usr.bin/ktrdump/ktrdump.c (revision 270727) +++ usr.bin/ktrdump/ktrdump.c (working copy) @@ -49,6 +49,7 @@ "usage: ktrdump [-cfqrtH] [-e execfile] [-i ktrfile] [-m corefile] [-o outfile]\n" static void usage(void); +static void dump_cpu_buf(FILE *, kvm_t *, int, int, struct ktr_entry **); static struct nlist nl[] = { { "_ktr_version" }, @@ -55,6 +56,7 @@ { "_ktr_entries" }, { "_ktr_idx" }, { "_ktr_buf" }, + { "_mp_ncpus" }, { NULL } }; @@ -83,21 +85,19 @@ int main(int ac, char **av) { - u_long parms[KTR_PARMS]; - struct ktr_entry *buf; - uintmax_t tlast, tnow; - unsigned long bufptr; + struct ktr_entry **buf; struct stat sb; kvm_t *kd; FILE *out; char *p; + int *idx; int version; int entries; int index, index2; - int parm; int in; int c; - int i = 0; + int ncpus; + int i, j; /* * Parse commandline arguments. @@ -160,31 +160,42 @@ if ((kd = kvm_openfiles(eflag ? execfile : NULL, mflag ? corefile : NULL, NULL, O_RDONLY, errbuf)) == NULL) errx(1, "%s", errbuf); - if (kvm_nlist(kd, nl) != 0 || - kvm_read(kd, nl[0].n_value, &version, sizeof(version)) == -1) + + /* + * Grab KTR version. + */ + if (kvm_nlist(kd, nl) != 0) errx(1, "%s", kvm_geterr(kd)); + if (kvm_read(kd, nl[0].n_value, &version, sizeof(version)) == -1) + errx(1, "%s", kvm_geterr(kd)); if (version != KTR_VERSION) errx(1, "ktr version mismatch"); - if (iflag) { - if (fstat(in, &sb) == -1) - errx(1, "stat"); - entries = sb.st_size / sizeof(*buf); - index = 0; - buf = mmap(NULL, sb.st_size, PROT_READ, MAP_SHARED, in, 0); - if (buf == MAP_FAILED) - errx(1, "mmap"); - } else { - if (kvm_read(kd, nl[1].n_value, &entries, sizeof(entries)) - == -1) + + /* + * Get the number of CPUS available in the system. + * XXXDAVIDE: Fix in the !SMP case? + */ + if (kvm_read(kd, nl[4].n_value, &ncpus, sizeof(ncpus)) == -1) + errx(1, "%s", kvm_geterr(kd)); + if (kvm_read(kd, nl[1].n_value, &entries, sizeof(entries) == -1)) + errx(1, "%s", kvm_geterr(kd)); + idx = malloc(sizeof(*idx) * ncpus); + if (idx == NULL) + errx(1, "Can't allocate memory"); + buf = malloc(sizeof(*buf) * ncpus); + if (buf == NULL) + errx(1, "Can't allocate memory"); + if (kvm_read(kd, nl[2].n_value, idx, sizeof(*idx) * ncpus) == -1) + errx(1, "%s", kvm_geterr(kd)); + if (kvm_read(kd, nl[3].n_value, buf, sizeof(*buf) * ncpus) == -1) + errx(1, "%s", kvm_geterr(kd)); + for (i = 0; i < ncpus; ++i) { + void *bufptr = buf[i]; + buf[i] = malloc(sizeof(**buf) * entries); + if (kvm_read(kd, (uintptr_t)bufptr, buf[i], + sizeof(**buf) * entries) == -1) { errx(1, "%s", kvm_geterr(kd)); - if ((buf = malloc(sizeof(*buf) * entries)) == NULL) - err(1, NULL); - if (kvm_read(kd, nl[2].n_value, &index, sizeof(index)) == -1 || - kvm_read(kd, nl[3].n_value, &bufptr, - sizeof(bufptr)) == -1 || - kvm_read(kd, bufptr, buf, sizeof(*buf) * entries) == -1 || - kvm_read(kd, nl[2].n_value, &index2, sizeof(index2)) == -1) - errx(1, "%s", kvm_geterr(kd)); + } } /* @@ -218,6 +229,22 @@ } /* + * Dump the KTR buffer for every CPU available in the system. + */ + for (i = 0; i < ncpus; ++i) + dump_cpu_buf(out, kd, i, entries, &buf[i]); + return (0); +} + +static void +dump_cpu_buf(FILE *out, kvm_t *kd, int cpu, int entries, struct ktr_entry **buf) +{ + u_long parms[KTR_PARMS]; + char *p; + uintmax_t tlast, tnow; + int c, i, index, index2, parm; + + /* * Now tear through the trace buffer. */ if (!iflag) { @@ -227,9 +254,9 @@ } tlast = -1; for (;;) { - if (buf[i].ktr_desc == NULL) + if (buf[i]->ktr_desc == NULL) break; - if (kvm_read(kd, (u_long)buf[i].ktr_desc, desc, + if (kvm_read(kd, (u_long)buf[i]->ktr_desc, desc, sizeof(desc)) == -1) errx(1, "%s", kvm_geterr(kd)); desc[sizeof(desc) - 1] = '\0'; @@ -249,7 +276,7 @@ case 'q': case 'L': case '.': goto next; case 's': - if (kvm_read(kd, (u_long)buf[i].ktr_parms[parm], + if (kvm_read(kd, (u_long)buf[i]->ktr_parms[parm], sbuf[parm], sizeof(sbuf[parm])) == -1) strcpy(sbuf[parm], "(null)"); sbuf[parm][sizeof(sbuf[0]) - 1] = '\0'; @@ -257,7 +284,7 @@ parm++; break; default: - parms[parm] = buf[i].ktr_parms[parm]; + parms[parm] = buf[i]->ktr_parms[parm]; parm++; break; } @@ -264,9 +291,9 @@ } fprintf(out, "%6d ", i); if (cflag) - fprintf(out, "%3d ", buf[i].ktr_cpu); + fprintf(out, "%3d ", buf[i]->ktr_cpu); if (tflag) { - tnow = (uintmax_t)buf[i].ktr_timestamp; + tnow = (uintmax_t)buf[i]->ktr_timestamp; if (rflag) { if (tlast == -1) tlast = tnow; @@ -277,15 +304,15 @@ fprintf(out, "%16ju ", tnow); } if (fflag) { - if (kvm_read(kd, (u_long)buf[i].ktr_file, fbuf, + if (kvm_read(kd, (u_long)buf[i]->ktr_file, fbuf, sizeof(fbuf)) == -1) strcpy(fbuf, "(null)"); snprintf(obuf, sizeof(obuf), "%s:%d", fbuf, - buf[i].ktr_line); + buf[i]->ktr_line); fprintf(out, "%-40s ", obuf); } if (hflag) - fprintf(out, "%p ", buf[i].ktr_thread); + fprintf(out, "%p ", buf[i]->ktr_thread); fprintf(out, desc, parms[0], parms[1], parms[2], parms[3], parms[4], parms[5]); fprintf(out, "\n"); @@ -306,10 +333,33 @@ break; } } - - return (0); } +#if 0 + if (iflag) { + if (fstat(in, &sb) == -1) + errx(1, "stat"); + entries = sb.st_size / sizeof(*buf); + index = 0; + buf = mmap(NULL, sb.st_size, PROT_READ, MAP_SHARED, in, 0); + if (buf == MAP_FAILED) + errx(1, "mmap"); + } else { + if (kvm_read(kd, nl[1].n_value, &entries, sizeof(entries)) + == -1) + errx(1, "%s", kvm_geterr(kd)); + if ((buf = malloc(sizeof(*buf) * entries)) == NULL) + err(1, NULL); + if (kvm_read(kd, nl[2].n_value, &index, sizeof(index)) == -1 || + kvm_read(kd, nl[3].n_value, &bufptr, + sizeof(bufptr)) == -1 || + kvm_read(kd, bufptr, buf, sizeof(*buf) * entries) == -1 || + kvm_read(kd, nl[2].n_value, &index2, sizeof(index2)) == -1) + errx(1, "%s", kvm_geterr(kd)); + } + +#endif + static void usage(void) {