kern_ktr.c revision 145142
1119936Sjhb/*- 2119936Sjhb * Copyright (c) 2000 John Baldwin <jhb@FreeBSD.org> 3119936Sjhb * All rights reserved. 465556Sjasone * 565556Sjasone * Redistribution and use in source and binary forms, with or without 665556Sjasone * modification, are permitted provided that the following conditions 765556Sjasone * are met: 865556Sjasone * 1. Redistributions of source code must retain the above copyright 965556Sjasone * notice, this list of conditions and the following disclaimer. 1065556Sjasone * 2. Redistributions in binary form must reproduce the above copyright 1165556Sjasone * notice, this list of conditions and the following disclaimer in the 1265556Sjasone * documentation and/or other materials provided with the distribution. 13119936Sjhb * 3. Neither the name of the author nor the names of any co-contributors 1465556Sjasone * may be used to endorse or promote products derived from this software 1565556Sjasone * without specific prior written permission. 1665556Sjasone * 17119936Sjhb * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND 1865556Sjasone * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE 1965556Sjasone * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE 20119936Sjhb * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE 21119936Sjhb * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL 22119936Sjhb * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS 23119936Sjhb * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) 24119936Sjhb * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT 25119936Sjhb * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY 26119936Sjhb * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF 27119936Sjhb * SUCH DAMAGE. 2865556Sjasone */ 2965556Sjasone 3065556Sjasone/* 3168420Sjhb * This module holds the global variables used by KTR and the ktr_tracepoint() 3268420Sjhb * function that does the actual tracing. 3365556Sjasone */ 3465556Sjasone 35116182Sobrien#include <sys/cdefs.h> 36116182Sobrien__FBSDID("$FreeBSD: head/sys/kern/kern_ktr.c 145142 2005-04-16 12:12:27Z rwatson $"); 37116182Sobrien 3870035Sjhb#include "opt_ddb.h" 3968420Sjhb#include "opt_ktr.h" 40103787Sjeff#include "opt_alq.h" 4168420Sjhb 4270035Sjhb#include <sys/param.h> 43103787Sjeff#include <sys/alq.h> 4470035Sjhb#include <sys/cons.h> 4570705Sjhb#include <sys/kernel.h> 4665556Sjasone#include <sys/ktr.h> 4768420Sjhb#include <sys/libkern.h> 4887793Sjhb#include <sys/proc.h> 4965556Sjasone#include <sys/sysctl.h> 5068420Sjhb#include <sys/systm.h> 5178784Sjhb#include <sys/time.h> 5265556Sjasone 5393503Sjake#include <machine/cpu.h> 5493950Sjake#ifdef __sparc64__ 5593950Sjake#include <machine/ktr.h> 5693950Sjake#endif 5793503Sjake 58103787Sjeff 5970035Sjhb#include <ddb/ddb.h> 6070035Sjhb 6178784Sjhb#ifndef KTR_ENTRIES 6278784Sjhb#define KTR_ENTRIES 1024 6378784Sjhb#endif 6478784Sjhb 6568420Sjhb#ifndef KTR_MASK 6668420Sjhb#define KTR_MASK (KTR_GEN) 6768420Sjhb#endif 6868420Sjhb 6968420Sjhb#ifndef KTR_CPUMASK 7068420Sjhb#define KTR_CPUMASK (~0) 7168420Sjhb#endif 7268420Sjhb 7393503Sjake#ifndef KTR_TIME 7493503Sjake#define KTR_TIME get_cyclecount() 7568420Sjhb#endif 7668420Sjhb 7793503Sjake#ifndef KTR_CPU 7893503Sjake#define KTR_CPU PCPU_GET(cpuid) 7970705Sjhb#endif 8070705Sjhb 8170705SjhbSYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options"); 8270705Sjhb 8377843Speterint ktr_cpumask = KTR_CPUMASK; 8477900SpeterTUNABLE_INT("debug.ktr.cpumask", &ktr_cpumask); 8570705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, cpumask, CTLFLAG_RW, &ktr_cpumask, 0, ""); 8665556Sjasone 8777843Speterint ktr_mask = KTR_MASK; 8877900SpeterTUNABLE_INT("debug.ktr.mask", &ktr_mask); 8970705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, mask, CTLFLAG_RW, &ktr_mask, 0, ""); 9065556Sjasone 91132583Srwatsonint ktr_compile = KTR_COMPILE; 92132583SrwatsonSYSCTL_INT(_debug_ktr, OID_AUTO, compile, CTLFLAG_RD, &ktr_compile, 0, ""); 93132583Srwatson 9465556Sjasoneint ktr_entries = KTR_ENTRIES; 9570705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, ""); 9665556Sjasone 9793503Sjakeint ktr_version = KTR_VERSION; 9893503SjakeSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, ""); 9993503Sjake 10065556Sjasonevolatile int ktr_idx = 0; 10165556Sjasonestruct ktr_entry ktr_buf[KTR_ENTRIES]; 10268420Sjhb 10393503Sjake#ifdef KTR_VERBOSE 10493503Sjakeint ktr_verbose = KTR_VERBOSE; 10577900SpeterTUNABLE_INT("debug.ktr.verbose", &ktr_verbose); 10670705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, ""); 10793503Sjake#endif 10868420Sjhb 109103787Sjeff#ifdef KTR_ALQ 110103787Sjeffstruct alq *ktr_alq; 111103787Sjeffchar ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out"; 112103787Sjeffint ktr_alq_cnt = 0; 113103787Sjeffint ktr_alq_depth = KTR_ENTRIES; 114103787Sjeffint ktr_alq_enabled = 0; 115103787Sjeffint ktr_alq_failed = 0; 116103787Sjeffint ktr_alq_max = 0; 117103787Sjeff 118103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0, 119103787Sjeff "Maximum number of entries to write"); 120103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0, 121103787Sjeff "Current number of written entries"); 122103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0, 123103787Sjeff "Number of times we overran the buffer"); 124103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0, 125103787Sjeff "Number of items in the write buffer"); 126103787SjeffSYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file, 127103787Sjeff sizeof(ktr_alq_file), "KTR logging file"); 128103787Sjeff 129103787Sjeffstatic int 130103787Sjeffsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS) 131103787Sjeff{ 132103787Sjeff int error; 133103787Sjeff int enable; 134103787Sjeff 135103787Sjeff enable = ktr_alq_enabled; 136103787Sjeff 137103787Sjeff error = sysctl_handle_int(oidp, &enable, 0, req); 138103787Sjeff if (error || !req->newptr) 139103787Sjeff return (error); 140103787Sjeff 141103787Sjeff if (enable) { 142103787Sjeff if (ktr_alq_enabled) 143103787Sjeff return (0); 144103787Sjeff error = suser(curthread); 145103787Sjeff if (error) 146103787Sjeff return (error); 147116697Srwatson error = alq_open(&ktr_alq, (const char *)ktr_alq_file, 148145142Srwatson req->td->td_ucred, ALQ_DEFAULT_CMODE, 149145142Srwatson sizeof(struct ktr_entry), ktr_alq_depth); 150103787Sjeff if (error == 0) { 151103787Sjeff ktr_mask &= ~KTR_ALQ_MASK; 152103787Sjeff ktr_alq_cnt = 0; 153103787Sjeff ktr_alq_failed = 0; 154103787Sjeff ktr_alq_enabled = 1; 155103787Sjeff } 156103787Sjeff } else { 157103787Sjeff if (ktr_alq_enabled == 0) 158103787Sjeff return (0); 159103787Sjeff ktr_alq_enabled = 0; 160103787Sjeff alq_close(ktr_alq); 161103787Sjeff ktr_alq = NULL; 162103787Sjeff } 163103787Sjeff 164103787Sjeff return (error); 165103787Sjeff} 166103787SjeffSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable, 167103787Sjeff CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable, 168103787Sjeff "I", "Enable KTR logging"); 169103787Sjeff#endif 170103787Sjeff 17168420Sjhbvoid 17293503Sjakektr_tracepoint(u_int mask, const char *file, int line, const char *format, 17393503Sjake u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5, 17493503Sjake u_long arg6) 17568420Sjhb{ 17668420Sjhb struct ktr_entry *entry; 177103787Sjeff#ifdef KTR_ALQ 178103787Sjeff struct ale *ale = NULL; 179103787Sjeff#else 18074903Sjhb int newindex, saveindex; 181103787Sjeff#endif 182103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 18387793Sjhb struct thread *td; 18493503Sjake#endif 18591904Sjhb int cpu; 18668420Sjhb 18769880Sjhb if (panicstr) 18869880Sjhb return; 18968420Sjhb if ((ktr_mask & mask) == 0) 19068420Sjhb return; 19193503Sjake cpu = KTR_CPU; 19293503Sjake if (((1 << cpu) & ktr_cpumask) == 0) 19393503Sjake return; 194103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 19587793Sjhb td = curthread; 196116101Sjhb if (td->td_pflags & TDP_INKTR) 19787793Sjhb return; 198116101Sjhb td->td_pflags |= TDP_INKTR; 19993503Sjake#endif 200103787Sjeff#ifdef KTR_ALQ 201103787Sjeff if (ktr_alq_enabled && 202103787Sjeff td->td_critnest == 0 && 203114471Sjulian (td->td_flags & TDF_IDLETD) == 0 && 204103995Sjeff td != ald_thread) { 205103787Sjeff if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max) 206103787Sjeff goto done; 207103787Sjeff if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) { 208103787Sjeff ktr_alq_failed++; 209103787Sjeff goto done; 210103787Sjeff } 211103787Sjeff ktr_alq_cnt++; 212103787Sjeff entry = (struct ktr_entry *)ale->ae_data; 213103787Sjeff } else 214103787Sjeff goto done; 215103787Sjeff#else 21668420Sjhb do { 21768420Sjhb saveindex = ktr_idx; 21868420Sjhb newindex = (saveindex + 1) & (KTR_ENTRIES - 1); 21968420Sjhb } while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0); 22068420Sjhb entry = &ktr_buf[saveindex]; 221103787Sjeff#endif 22293503Sjake entry->ktr_timestamp = KTR_TIME; 22391904Sjhb entry->ktr_cpu = cpu; 224112105Sjhb if (file != NULL) 225112105Sjhb while (strncmp(file, "../", 3) == 0) 226112105Sjhb file += 3; 22793503Sjake entry->ktr_file = file; 22868420Sjhb entry->ktr_line = line; 22993503Sjake#ifdef KTR_VERBOSE 23068420Sjhb if (ktr_verbose) { 23168782Sjhb#ifdef SMP 23293503Sjake printf("cpu%d ", cpu); 23368782Sjhb#endif 23493503Sjake if (ktr_verbose > 1) { 23593503Sjake printf("%s.%d\t", entry->ktr_file, 23693503Sjake entry->ktr_line); 23793503Sjake } 23893503Sjake printf(format, arg1, arg2, arg3, arg4, arg5, arg6); 23968420Sjhb printf("\n"); 24068420Sjhb } 24193503Sjake#endif 24268420Sjhb entry->ktr_desc = format; 24393503Sjake entry->ktr_parms[0] = arg1; 24493503Sjake entry->ktr_parms[1] = arg2; 24593503Sjake entry->ktr_parms[2] = arg3; 24693503Sjake entry->ktr_parms[3] = arg4; 24793503Sjake entry->ktr_parms[4] = arg5; 24893503Sjake entry->ktr_parms[5] = arg6; 249103787Sjeff#ifdef KTR_ALQ 250103787Sjeff if (ale) 251103787Sjeff alq_post(ktr_alq, ale); 252103787Sjeffdone: 253103787Sjeff#endif 254103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 255116101Sjhb td->td_pflags &= ~TDP_INKTR; 25668420Sjhb#endif 25768420Sjhb} 25870035Sjhb 25970035Sjhb#ifdef DDB 26070035Sjhb 26170035Sjhbstruct tstate { 26270035Sjhb int cur; 26370035Sjhb int first; 26470035Sjhb}; 26570035Sjhbstatic struct tstate tstate; 26670035Sjhbstatic int db_ktr_verbose; 26770035Sjhbstatic int db_mach_vtrace(void); 26870035Sjhb 26972755SjhbDB_SHOW_COMMAND(ktr, db_ktr_all) 27070035Sjhb{ 271118362Sjhb int quit; 272118269Sjhb 273118269Sjhb quit = 0; 27470035Sjhb tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1); 27570035Sjhb tstate.first = -1; 27670035Sjhb if (strcmp(modif, "v") == 0) 27770035Sjhb db_ktr_verbose = 1; 27870035Sjhb else 27970035Sjhb db_ktr_verbose = 0; 280118269Sjhb if (strcmp(modif, "a") == 0) { 281118269Sjhb while (cncheckc() != -1) 282118269Sjhb if (db_mach_vtrace() == 0) 28372755Sjhb break; 284118269Sjhb } else { 285137117Sjhb db_setup_paging(db_simple_pager, &quit, db_lines_per_page); 286118269Sjhb while (!quit) 287118269Sjhb if (db_mach_vtrace() == 0) 28872755Sjhb break; 289118269Sjhb } 29070035Sjhb} 29170035Sjhb 29270035Sjhbstatic int 29370035Sjhbdb_mach_vtrace(void) 29470035Sjhb{ 29570035Sjhb struct ktr_entry *kp; 29670035Sjhb 29770035Sjhb if (tstate.cur == tstate.first) { 29870035Sjhb db_printf("--- End of trace buffer ---\n"); 29970035Sjhb return (0); 30070035Sjhb } 30170035Sjhb kp = &ktr_buf[tstate.cur]; 30270035Sjhb 30370035Sjhb /* Skip over unused entries. */ 30472755Sjhb if (kp->ktr_desc == NULL) { 30572755Sjhb db_printf("--- End of trace buffer ---\n"); 30672755Sjhb return (0); 30772755Sjhb } 30872755Sjhb db_printf("%d: ", tstate.cur); 30970035Sjhb#ifdef SMP 31072755Sjhb db_printf("cpu%d ", kp->ktr_cpu); 31170035Sjhb#endif 31293503Sjake if (db_ktr_verbose) { 31393503Sjake db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp, 31493503Sjake kp->ktr_file, kp->ktr_line); 31593503Sjake } 31693503Sjake db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1], 31793503Sjake kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4], 31893503Sjake kp->ktr_parms[5]); 31972755Sjhb db_printf("\n"); 32070035Sjhb 32170035Sjhb if (tstate.first == -1) 32270035Sjhb tstate.first = tstate.cur; 32370035Sjhb 32470035Sjhb if (--tstate.cur < 0) 32570035Sjhb tstate.cur = KTR_ENTRIES - 1; 32670035Sjhb 32770035Sjhb return (1); 32870035Sjhb} 32970035Sjhb 33070035Sjhb#endif /* DDB */ 331