kern_ktr.c revision 119936
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 119936 2003-09-10 01:09:32Z jhb $"); 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 9165556Sjasoneint ktr_entries = KTR_ENTRIES; 9270705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, ""); 9365556Sjasone 9493503Sjakeint ktr_version = KTR_VERSION; 9593503SjakeSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, ""); 9693503Sjake 9765556Sjasonevolatile int ktr_idx = 0; 9865556Sjasonestruct ktr_entry ktr_buf[KTR_ENTRIES]; 9968420Sjhb 10093503Sjake#ifdef KTR_VERBOSE 10193503Sjakeint ktr_verbose = KTR_VERBOSE; 10277900SpeterTUNABLE_INT("debug.ktr.verbose", &ktr_verbose); 10370705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, ""); 10493503Sjake#endif 10568420Sjhb 106103787Sjeff#ifdef KTR_ALQ 107103787Sjeffstruct alq *ktr_alq; 108103787Sjeffchar ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out"; 109103787Sjeffint ktr_alq_cnt = 0; 110103787Sjeffint ktr_alq_depth = KTR_ENTRIES; 111103787Sjeffint ktr_alq_enabled = 0; 112103787Sjeffint ktr_alq_failed = 0; 113103787Sjeffint ktr_alq_max = 0; 114103787Sjeff 115103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0, 116103787Sjeff "Maximum number of entries to write"); 117103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0, 118103787Sjeff "Current number of written entries"); 119103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0, 120103787Sjeff "Number of times we overran the buffer"); 121103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0, 122103787Sjeff "Number of items in the write buffer"); 123103787SjeffSYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file, 124103787Sjeff sizeof(ktr_alq_file), "KTR logging file"); 125103787Sjeff 126103787Sjeffstatic int 127103787Sjeffsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS) 128103787Sjeff{ 129103787Sjeff int error; 130103787Sjeff int enable; 131103787Sjeff 132103787Sjeff enable = ktr_alq_enabled; 133103787Sjeff 134103787Sjeff error = sysctl_handle_int(oidp, &enable, 0, req); 135103787Sjeff if (error || !req->newptr) 136103787Sjeff return (error); 137103787Sjeff 138103787Sjeff if (enable) { 139103787Sjeff if (ktr_alq_enabled) 140103787Sjeff return (0); 141103787Sjeff error = suser(curthread); 142103787Sjeff if (error) 143103787Sjeff return (error); 144116697Srwatson error = alq_open(&ktr_alq, (const char *)ktr_alq_file, 145116697Srwatson req->td->td_ucred, sizeof(struct ktr_entry), 146116697Srwatson ktr_alq_depth); 147103787Sjeff if (error == 0) { 148103787Sjeff ktr_mask &= ~KTR_ALQ_MASK; 149103787Sjeff ktr_alq_cnt = 0; 150103787Sjeff ktr_alq_failed = 0; 151103787Sjeff ktr_alq_enabled = 1; 152103787Sjeff } 153103787Sjeff } else { 154103787Sjeff if (ktr_alq_enabled == 0) 155103787Sjeff return (0); 156103787Sjeff ktr_alq_enabled = 0; 157103787Sjeff alq_close(ktr_alq); 158103787Sjeff ktr_alq = NULL; 159103787Sjeff } 160103787Sjeff 161103787Sjeff return (error); 162103787Sjeff} 163103787SjeffSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable, 164103787Sjeff CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable, 165103787Sjeff "I", "Enable KTR logging"); 166103787Sjeff#endif 167103787Sjeff 16868420Sjhbvoid 16993503Sjakektr_tracepoint(u_int mask, const char *file, int line, const char *format, 17093503Sjake u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5, 17193503Sjake u_long arg6) 17268420Sjhb{ 17368420Sjhb struct ktr_entry *entry; 174103787Sjeff#ifdef KTR_ALQ 175103787Sjeff struct ale *ale = NULL; 176103787Sjeff#else 17774903Sjhb int newindex, saveindex; 178103787Sjeff#endif 179103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 18087793Sjhb struct thread *td; 18193503Sjake#endif 18291904Sjhb int cpu; 18368420Sjhb 18469880Sjhb if (panicstr) 18569880Sjhb return; 18668420Sjhb if ((ktr_mask & mask) == 0) 18768420Sjhb return; 18893503Sjake cpu = KTR_CPU; 18993503Sjake if (((1 << cpu) & ktr_cpumask) == 0) 19093503Sjake return; 191103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 19287793Sjhb td = curthread; 193116101Sjhb if (td->td_pflags & TDP_INKTR) 19487793Sjhb return; 195116101Sjhb td->td_pflags |= TDP_INKTR; 19693503Sjake#endif 197103787Sjeff#ifdef KTR_ALQ 198103787Sjeff if (ktr_alq_enabled && 199103787Sjeff td->td_critnest == 0 && 200114471Sjulian (td->td_flags & TDF_IDLETD) == 0 && 201103995Sjeff td != ald_thread) { 202103787Sjeff if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max) 203103787Sjeff goto done; 204103787Sjeff if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) { 205103787Sjeff ktr_alq_failed++; 206103787Sjeff goto done; 207103787Sjeff } 208103787Sjeff ktr_alq_cnt++; 209103787Sjeff entry = (struct ktr_entry *)ale->ae_data; 210103787Sjeff } else 211103787Sjeff goto done; 212103787Sjeff#else 21368420Sjhb do { 21468420Sjhb saveindex = ktr_idx; 21568420Sjhb newindex = (saveindex + 1) & (KTR_ENTRIES - 1); 21668420Sjhb } while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0); 21768420Sjhb entry = &ktr_buf[saveindex]; 218103787Sjeff#endif 21993503Sjake entry->ktr_timestamp = KTR_TIME; 22091904Sjhb entry->ktr_cpu = cpu; 221112105Sjhb if (file != NULL) 222112105Sjhb while (strncmp(file, "../", 3) == 0) 223112105Sjhb file += 3; 22493503Sjake entry->ktr_file = file; 22568420Sjhb entry->ktr_line = line; 22693503Sjake#ifdef KTR_VERBOSE 22768420Sjhb if (ktr_verbose) { 22868782Sjhb#ifdef SMP 22993503Sjake printf("cpu%d ", cpu); 23068782Sjhb#endif 23193503Sjake if (ktr_verbose > 1) { 23293503Sjake printf("%s.%d\t", entry->ktr_file, 23393503Sjake entry->ktr_line); 23493503Sjake } 23593503Sjake printf(format, arg1, arg2, arg3, arg4, arg5, arg6); 23668420Sjhb printf("\n"); 23768420Sjhb } 23893503Sjake#endif 23968420Sjhb entry->ktr_desc = format; 24093503Sjake entry->ktr_parms[0] = arg1; 24193503Sjake entry->ktr_parms[1] = arg2; 24293503Sjake entry->ktr_parms[2] = arg3; 24393503Sjake entry->ktr_parms[3] = arg4; 24493503Sjake entry->ktr_parms[4] = arg5; 24593503Sjake entry->ktr_parms[5] = arg6; 246103787Sjeff#ifdef KTR_ALQ 247103787Sjeff if (ale) 248103787Sjeff alq_post(ktr_alq, ale); 249103787Sjeffdone: 250103787Sjeff#endif 251103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 252116101Sjhb td->td_pflags &= ~TDP_INKTR; 25368420Sjhb#endif 25468420Sjhb} 25570035Sjhb 25670035Sjhb#ifdef DDB 25770035Sjhb 25870035Sjhbstruct tstate { 25970035Sjhb int cur; 26070035Sjhb int first; 26170035Sjhb}; 26270035Sjhbstatic struct tstate tstate; 26370035Sjhbstatic int db_ktr_verbose; 26470035Sjhbstatic int db_mach_vtrace(void); 26570035Sjhb 26672755Sjhb#define NUM_LINES_PER_PAGE 18 26772755Sjhb 26872755SjhbDB_SHOW_COMMAND(ktr, db_ktr_all) 26970035Sjhb{ 270118362Sjhb int quit; 271118269Sjhb 272118269Sjhb quit = 0; 27370035Sjhb tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1); 27470035Sjhb tstate.first = -1; 27570035Sjhb if (strcmp(modif, "v") == 0) 27670035Sjhb db_ktr_verbose = 1; 27770035Sjhb else 27870035Sjhb db_ktr_verbose = 0; 279118269Sjhb if (strcmp(modif, "a") == 0) { 280118269Sjhb while (cncheckc() != -1) 281118269Sjhb if (db_mach_vtrace() == 0) 28272755Sjhb break; 283118269Sjhb } else { 284118269Sjhb db_setup_paging(db_simple_pager, &quit, DB_LINES_PER_PAGE); 285118269Sjhb while (!quit) 286118269Sjhb if (db_mach_vtrace() == 0) 28772755Sjhb break; 288118269Sjhb } 28970035Sjhb} 29070035Sjhb 29170035Sjhbstatic int 29270035Sjhbdb_mach_vtrace(void) 29370035Sjhb{ 29470035Sjhb struct ktr_entry *kp; 29570035Sjhb 29670035Sjhb if (tstate.cur == tstate.first) { 29770035Sjhb db_printf("--- End of trace buffer ---\n"); 29870035Sjhb return (0); 29970035Sjhb } 30070035Sjhb kp = &ktr_buf[tstate.cur]; 30170035Sjhb 30270035Sjhb /* Skip over unused entries. */ 30372755Sjhb if (kp->ktr_desc == NULL) { 30472755Sjhb db_printf("--- End of trace buffer ---\n"); 30572755Sjhb return (0); 30672755Sjhb } 30772755Sjhb db_printf("%d: ", tstate.cur); 30870035Sjhb#ifdef SMP 30972755Sjhb db_printf("cpu%d ", kp->ktr_cpu); 31070035Sjhb#endif 31193503Sjake if (db_ktr_verbose) { 31293503Sjake db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp, 31393503Sjake kp->ktr_file, kp->ktr_line); 31493503Sjake } 31593503Sjake db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1], 31693503Sjake kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4], 31793503Sjake kp->ktr_parms[5]); 31872755Sjhb db_printf("\n"); 31970035Sjhb 32070035Sjhb if (tstate.first == -1) 32170035Sjhb tstate.first = tstate.cur; 32270035Sjhb 32370035Sjhb if (--tstate.cur < 0) 32470035Sjhb tstate.cur = KTR_ENTRIES - 1; 32570035Sjhb 32670035Sjhb return (1); 32770035Sjhb} 32870035Sjhb 32970035Sjhb#endif /* DDB */ 330