kern_ktr.c revision 116697
1234353Sdim/* 2198090Srdivacky * Copyright (c) 2000 3198090Srdivacky * John Baldwin <jhb@FreeBSD.org>. All rights reserved. 4198090Srdivacky * 5198090Srdivacky * Redistribution and use in source and binary forms, with or without 6198090Srdivacky * modification, are permitted provided that the following conditions 7198090Srdivacky * are met: 8198090Srdivacky * 1. Redistributions of source code must retain the above copyright 9198090Srdivacky * notice, this list of conditions and the following disclaimer. 10198090Srdivacky * 2. Redistributions in binary form must reproduce the above copyright 11198090Srdivacky * notice, this list of conditions and the following disclaimer in the 12198090Srdivacky * documentation and/or other materials provided with the distribution. 13198090Srdivacky * 4. Neither the name of the author nor the names of any co-contributors 14198090Srdivacky * may be used to endorse or promote products derived from this software 15249423Sdim * without specific prior written permission. 16239462Sdim * 17239462Sdim * THIS SOFTWARE IS PROVIDED BY JOHN BALDWIN AND CONTRIBUTORS ``AS IS'' AND 18239462Sdim * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE 19239462Sdim * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE 20239462Sdim * ARE DISCLAIMED. IN NO EVENT SHALL JOHN BALDWIN OR THE VOICES IN HIS HEAD 21249423Sdim * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR 22249423Sdim * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF 23249423Sdim * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS 24249423Sdim * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN 25249423Sdim * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) 26249423Sdim * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF 27249423Sdim * THE POSSIBILITY OF SUCH DAMAGE. 28249423Sdim */ 29249423Sdim 30239462Sdim/* 31239462Sdim * This module holds the global variables used by KTR and the ktr_tracepoint() 32239462Sdim * function that does the actual tracing. 33218893Sdim */ 34280031Sdim 35239462Sdim#include <sys/cdefs.h> 36198090Srdivacky__FBSDID("$FreeBSD: head/sys/kern/kern_ktr.c 116697 2003-06-22 22:28:56Z rwatson $"); 37198090Srdivacky 38218893Sdim#include "opt_ddb.h" 39198090Srdivacky#include "opt_ktr.h" 40198090Srdivacky#include "opt_alq.h" 41276479Sdim 42276479Sdim#include <sys/param.h> 43198090Srdivacky#include <sys/alq.h> 44198090Srdivacky#include <sys/cons.h> 45198090Srdivacky#include <sys/kernel.h> 46198090Srdivacky#include <sys/ktr.h> 47261991Sdim#include <sys/libkern.h> 48288943Sdim#include <sys/proc.h> 49288943Sdim#include <sys/sysctl.h> 50261991Sdim#include <sys/systm.h> 51261991Sdim#include <sys/time.h> 52261991Sdim 53296417Sdim#include <machine/cpu.h> 54261991Sdim#ifdef __sparc64__ 55261991Sdim#include <machine/ktr.h> 56261991Sdim#endif 57261991Sdim 58261991Sdim 59261991Sdim#include <ddb/ddb.h> 60261991Sdim 61261991Sdim#ifndef KTR_ENTRIES 62198090Srdivacky#define KTR_ENTRIES 1024 63261991Sdim#endif 64261991Sdim 65288943Sdim#ifndef KTR_MASK 66276479Sdim#define KTR_MASK (KTR_GEN) 67276479Sdim#endif 68198090Srdivacky 69276479Sdim#ifndef KTR_CPUMASK 70276479Sdim#define KTR_CPUMASK (~0) 71261991Sdim#endif 72261991Sdim 73261991Sdim#ifndef KTR_TIME 74261991Sdim#define KTR_TIME get_cyclecount() 75261991Sdim#endif 76261991Sdim 77261991Sdim#ifndef KTR_CPU 78261991Sdim#define KTR_CPU PCPU_GET(cpuid) 79261991Sdim#endif 80261991Sdim 81261991SdimSYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options"); 82198090Srdivacky 83198090Srdivackyint ktr_cpumask = KTR_CPUMASK; 84234353SdimTUNABLE_INT("debug.ktr.cpumask", &ktr_cpumask); 85288943SdimSYSCTL_INT(_debug_ktr, OID_AUTO, cpumask, CTLFLAG_RW, &ktr_cpumask, 0, ""); 86288943Sdim 87198090Srdivackyint ktr_mask = KTR_MASK; 88234353SdimTUNABLE_INT("debug.ktr.mask", &ktr_mask); 89288943SdimSYSCTL_INT(_debug_ktr, OID_AUTO, mask, CTLFLAG_RW, &ktr_mask, 0, ""); 90198090Srdivacky 91198090Srdivackyint ktr_entries = KTR_ENTRIES; 92234353SdimSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, ""); 93198090Srdivacky 94198090Srdivackyint ktr_version = KTR_VERSION; 95224145SdimSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, ""); 96224145Sdim 97288943Sdimvolatile int ktr_idx = 0; 98288943Sdimstruct ktr_entry ktr_buf[KTR_ENTRIES]; 99288943Sdim 100288943Sdim#ifdef KTR_VERBOSE 101288943Sdimint ktr_verbose = KTR_VERBOSE; 102288943SdimTUNABLE_INT("debug.ktr.verbose", &ktr_verbose); 103288943SdimSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, ""); 104288943Sdim#endif 105280031Sdim 106261991Sdim#ifdef KTR_ALQ 107261991Sdimstruct alq *ktr_alq; 108276479Sdimchar ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out"; 109261991Sdimint ktr_alq_cnt = 0; 110261991Sdimint ktr_alq_depth = KTR_ENTRIES; 111276479Sdimint ktr_alq_enabled = 0; 112198090Srdivackyint ktr_alq_failed = 0; 113210299Sedint ktr_alq_max = 0; 114210299Sed 115296417SdimSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0, 116296417Sdim "Maximum number of entries to write"); 117198090SrdivackySYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0, 118203954Srdivacky "Current number of written entries"); 119226633SdimSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0, 120276479Sdim "Number of times we overran the buffer"); 121198090SrdivackySYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0, 122198090Srdivacky "Number of items in the write buffer"); 123198090SrdivackySYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file, 124198090Srdivacky sizeof(ktr_alq_file), "KTR logging file"); 125204792Srdivacky 126204792Srdivackystatic int 127234353Sdimsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS) 128234353Sdim{ 129234353Sdim int error; 130234353Sdim int enable; 131234353Sdim 132234353Sdim enable = ktr_alq_enabled; 133234353Sdim 134234353Sdim error = sysctl_handle_int(oidp, &enable, 0, req); 135288943Sdim if (error || !req->newptr) 136288943Sdim return (error); 137234353Sdim 138234353Sdim if (enable) { 139261991Sdim if (ktr_alq_enabled) 140261991Sdim return (0); 141261991Sdim error = suser(curthread); 142204792Srdivacky if (error) 143204792Srdivacky return (error); 144198090Srdivacky error = alq_open(&ktr_alq, (const char *)ktr_alq_file, 145198090Srdivacky req->td->td_ucred, sizeof(struct ktr_entry), 146234353Sdim ktr_alq_depth); 147280031Sdim if (error == 0) { 148280031Sdim ktr_mask &= ~KTR_ALQ_MASK; 149261991Sdim ktr_alq_cnt = 0; 150198090Srdivacky ktr_alq_failed = 0; 151198090Srdivacky ktr_alq_enabled = 1; 152198090Srdivacky } 153198090Srdivacky } else { 154198090Srdivacky if (ktr_alq_enabled == 0) 155234353Sdim return (0); 156234353Sdim ktr_alq_enabled = 0; 157234353Sdim alq_close(ktr_alq); 158234353Sdim ktr_alq = NULL; 159276479Sdim } 160234353Sdim 161234353Sdim return (error); 162234353Sdim} 163261991SdimSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable, 164261991Sdim CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable, 165261991Sdim "I", "Enable KTR logging"); 166261991Sdim#endif 167234353Sdim 168234353Sdimvoid 169234353Sdimktr_tracepoint(u_int mask, const char *file, int line, const char *format, 170234353Sdim u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5, 171234353Sdim u_long arg6) 172234353Sdim{ 173198090Srdivacky struct ktr_entry *entry; 174198090Srdivacky#ifdef KTR_ALQ 175261991Sdim struct ale *ale = NULL; 176261991Sdim#else 177198090Srdivacky int newindex, saveindex; 178234353Sdim#endif 179234353Sdim#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 180234353Sdim struct thread *td; 181234353Sdim#endif 182296417Sdim int cpu; 183296417Sdim 184234353Sdim if (panicstr) 185234353Sdim return; 186198090Srdivacky if ((ktr_mask & mask) == 0) 187234353Sdim return; 188198090Srdivacky cpu = KTR_CPU; 189198090Srdivacky if (((1 << cpu) & ktr_cpumask) == 0) 190226633Sdim return; 191226633Sdim#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 192261991Sdim td = curthread; 193261991Sdim if (td->td_pflags & TDP_INKTR) 194296417Sdim return; 195226633Sdim td->td_pflags |= TDP_INKTR; 196226633Sdim#endif 197226633Sdim#ifdef KTR_ALQ 198226633Sdim if (ktr_alq_enabled && 199288943Sdim td->td_critnest == 0 && 200288943Sdim (td->td_flags & TDF_IDLETD) == 0 && 201276479Sdim td != ald_thread) { 202296417Sdim if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max) 203226633Sdim goto done; 204226633Sdim if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) { 205226633Sdim ktr_alq_failed++; 206226633Sdim goto done; 207296417Sdim } 208296417Sdim ktr_alq_cnt++; 209226633Sdim entry = (struct ktr_entry *)ale->ae_data; 210234353Sdim } else 211288943Sdim goto done; 212288943Sdim#else 213234353Sdim do { 214234353Sdim saveindex = ktr_idx; 215288943Sdim newindex = (saveindex + 1) & (KTR_ENTRIES - 1); 216288943Sdim } while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0); 217226633Sdim entry = &ktr_buf[saveindex]; 218243830Sdim#endif 219234353Sdim entry->ktr_timestamp = KTR_TIME; 220288943Sdim entry->ktr_cpu = cpu; 221288943Sdim if (file != NULL) 222226633Sdim while (strncmp(file, "../", 3) == 0) 223226633Sdim file += 3; 224234353Sdim entry->ktr_file = file; 225226633Sdim entry->ktr_line = line; 226226633Sdim#ifdef KTR_VERBOSE 227226633Sdim if (ktr_verbose) { 228243830Sdim#ifdef SMP 229226633Sdim printf("cpu%d ", cpu); 230288943Sdim#endif 231288943Sdim if (ktr_verbose > 1) { 232288943Sdim printf("%s.%d\t", entry->ktr_file, 233261991Sdim entry->ktr_line); 234261991Sdim } 235261991Sdim printf(format, arg1, arg2, arg3, arg4, arg5, arg6); 236226633Sdim printf("\n"); 237226633Sdim } 238288943Sdim#endif 239288943Sdim entry->ktr_desc = format; 240288943Sdim entry->ktr_parms[0] = arg1; 241243830Sdim entry->ktr_parms[1] = arg2; 242226633Sdim entry->ktr_parms[2] = arg3; 243226633Sdim entry->ktr_parms[3] = arg4; 244226633Sdim entry->ktr_parms[4] = arg5; 245226633Sdim entry->ktr_parms[5] = arg6; 246226633Sdim#ifdef KTR_ALQ 247226633Sdim if (ale) 248226633Sdim alq_post(ktr_alq, ale); 249226633Sdimdone: 250234353Sdim#endif 251226633Sdim#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 252226633Sdim td->td_pflags &= ~TDP_INKTR; 253226633Sdim#endif 254226633Sdim} 255296417Sdim 256226633Sdim#ifdef DDB 257296417Sdim 258296417Sdimstruct tstate { 259226633Sdim int cur; 260276479Sdim int first; 261276479Sdim}; 262276479Sdimstatic struct tstate tstate; 263296417Sdimstatic int db_ktr_verbose; 264296417Sdimstatic int db_mach_vtrace(void); 265296417Sdim 266226633Sdim#define NUM_LINES_PER_PAGE 18 267276479Sdim 268296417SdimDB_SHOW_COMMAND(ktr, db_ktr_all) 269226633Sdim{ 270226633Sdim int c, lines; 271226633Sdim int all = 0; 272226633Sdim 273226633Sdim lines = NUM_LINES_PER_PAGE; 274234353Sdim tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1); 275261991Sdim tstate.first = -1; 276226633Sdim if (strcmp(modif, "v") == 0) 277261991Sdim db_ktr_verbose = 1; 278261991Sdim else 279261991Sdim db_ktr_verbose = 0; 280226633Sdim if (strcmp(modif, "a") == 0) 281226633Sdim all = 1; 282226633Sdim while (db_mach_vtrace()) 283296417Sdim if (all) { 284261991Sdim if (cncheckc() != -1) 285261991Sdim return; 286226633Sdim } else if (--lines == 0) { 287276479Sdim db_printf("--More--"); 288276479Sdim c = cngetc(); 289261991Sdim db_printf("\r"); 290226633Sdim switch (c) { 291226633Sdim case '\n': /* one more line */ 292226633Sdim lines = 1; 293226633Sdim break; 294226633Sdim case ' ': /* one more page */ 295226633Sdim lines = NUM_LINES_PER_PAGE; 296226633Sdim break; 297226633Sdim default: 298261991Sdim db_printf("\n"); 299276479Sdim return; 300276479Sdim } 301276479Sdim } 302276479Sdim} 303226633Sdim 304226633Sdimstatic int 305226633Sdimdb_mach_vtrace(void) 306261991Sdim{ 307226633Sdim struct ktr_entry *kp; 308226633Sdim 309226633Sdim if (tstate.cur == tstate.first) { 310226633Sdim db_printf("--- End of trace buffer ---\n"); 311226633Sdim return (0); 312226633Sdim } 313226633Sdim kp = &ktr_buf[tstate.cur]; 314226633Sdim 315226633Sdim /* Skip over unused entries. */ 316226633Sdim if (kp->ktr_desc == NULL) { 317226633Sdim db_printf("--- End of trace buffer ---\n"); 318226633Sdim return (0); 319226633Sdim } 320226633Sdim db_printf("%d: ", tstate.cur); 321226633Sdim#ifdef SMP 322226633Sdim db_printf("cpu%d ", kp->ktr_cpu); 323226633Sdim#endif 324226633Sdim if (db_ktr_verbose) { 325226633Sdim db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp, 326226633Sdim kp->ktr_file, kp->ktr_line); 327226633Sdim } 328226633Sdim db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1], 329234353Sdim kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4], 330261991Sdim kp->ktr_parms[5]); 331226633Sdim db_printf("\n"); 332234353Sdim 333226633Sdim if (tstate.first == -1) 334226633Sdim tstate.first = tstate.cur; 335226633Sdim 336226633Sdim if (--tstate.cur < 0) 337226633Sdim tstate.cur = KTR_ENTRIES - 1; 338226633Sdim 339226633Sdim return (1); 340226633Sdim} 341234353Sdim 342226633Sdim#endif /* DDB */ 343226633Sdim