kern_ktr.c revision 116697
165556Sjasone/* 265556Sjasone * Copyright (c) 2000 365556Sjasone * John Baldwin <jhb@FreeBSD.org>. 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. 1365556Sjasone * 4. 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 * 1769012Sjhb * THIS SOFTWARE IS PROVIDED BY JOHN BALDWIN 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 2069012Sjhb * ARE DISCLAIMED. IN NO EVENT SHALL JOHN BALDWIN OR THE VOICES IN HIS HEAD 2165556Sjasone * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR 2265556Sjasone * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF 2365556Sjasone * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS 2465556Sjasone * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN 2565556Sjasone * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) 2665556Sjasone * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF 2765556Sjasone * THE POSSIBILITY OF 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 116697 2003-06-22 22:28:56Z 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 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{ 27072755Sjhb int c, lines; 271111270Sjake int all = 0; 27270035Sjhb 27372755Sjhb lines = NUM_LINES_PER_PAGE; 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; 280111270Sjake if (strcmp(modif, "a") == 0) 281111270Sjake all = 1; 28272755Sjhb while (db_mach_vtrace()) 283111270Sjake if (all) { 284111270Sjake if (cncheckc() != -1) 285111270Sjake return; 286111270Sjake } else if (--lines == 0) { 28772755Sjhb db_printf("--More--"); 28872755Sjhb c = cngetc(); 28972755Sjhb db_printf("\r"); 29072755Sjhb switch (c) { 29172755Sjhb case '\n': /* one more line */ 29272755Sjhb lines = 1; 29372755Sjhb break; 29472755Sjhb case ' ': /* one more page */ 29572755Sjhb lines = NUM_LINES_PER_PAGE; 29672755Sjhb break; 29772755Sjhb default: 29872755Sjhb db_printf("\n"); 29972755Sjhb return; 30072755Sjhb } 30172755Sjhb } 30270035Sjhb} 30370035Sjhb 30470035Sjhbstatic int 30570035Sjhbdb_mach_vtrace(void) 30670035Sjhb{ 30770035Sjhb struct ktr_entry *kp; 30870035Sjhb 30970035Sjhb if (tstate.cur == tstate.first) { 31070035Sjhb db_printf("--- End of trace buffer ---\n"); 31170035Sjhb return (0); 31270035Sjhb } 31370035Sjhb kp = &ktr_buf[tstate.cur]; 31470035Sjhb 31570035Sjhb /* Skip over unused entries. */ 31672755Sjhb if (kp->ktr_desc == NULL) { 31772755Sjhb db_printf("--- End of trace buffer ---\n"); 31872755Sjhb return (0); 31972755Sjhb } 32072755Sjhb db_printf("%d: ", tstate.cur); 32170035Sjhb#ifdef SMP 32272755Sjhb db_printf("cpu%d ", kp->ktr_cpu); 32370035Sjhb#endif 32493503Sjake if (db_ktr_verbose) { 32593503Sjake db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp, 32693503Sjake kp->ktr_file, kp->ktr_line); 32793503Sjake } 32893503Sjake db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1], 32993503Sjake kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4], 33093503Sjake kp->ktr_parms[5]); 33172755Sjhb db_printf("\n"); 33270035Sjhb 33370035Sjhb if (tstate.first == -1) 33470035Sjhb tstate.first = tstate.cur; 33570035Sjhb 33670035Sjhb if (--tstate.cur < 0) 33770035Sjhb tstate.cur = KTR_ENTRIES - 1; 33870035Sjhb 33970035Sjhb return (1); 34070035Sjhb} 34170035Sjhb 34270035Sjhb#endif /* DDB */ 343