kern_ktr.c revision 103995
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 * $FreeBSD: head/sys/kern/kern_ktr.c 103995 2002-09-26 07:38:56Z jeff $ 3065556Sjasone */ 3165556Sjasone 3265556Sjasone/* 3368420Sjhb * This module holds the global variables used by KTR and the ktr_tracepoint() 3468420Sjhb * function that does the actual tracing. 3565556Sjasone */ 3665556Sjasone 3770035Sjhb#include "opt_ddb.h" 3868420Sjhb#include "opt_ktr.h" 39103787Sjeff#include "opt_alq.h" 4068420Sjhb 4170035Sjhb#include <sys/param.h> 42103787Sjeff#include <sys/alq.h> 4370035Sjhb#include <sys/cons.h> 4470705Sjhb#include <sys/kernel.h> 4565556Sjasone#include <sys/ktr.h> 4668420Sjhb#include <sys/libkern.h> 4787793Sjhb#include <sys/proc.h> 4865556Sjasone#include <sys/sysctl.h> 4968420Sjhb#include <sys/systm.h> 5078784Sjhb#include <sys/time.h> 5165556Sjasone 5293503Sjake#include <machine/cpu.h> 5393950Sjake#ifdef __sparc64__ 5493950Sjake#include <machine/ktr.h> 5593950Sjake#endif 5693503Sjake 57103787Sjeff 5870035Sjhb#include <ddb/ddb.h> 5970035Sjhb 6078784Sjhb#ifndef KTR_ENTRIES 6178784Sjhb#define KTR_ENTRIES 1024 6278784Sjhb#endif 6378784Sjhb 6468420Sjhb#ifndef KTR_MASK 6568420Sjhb#define KTR_MASK (KTR_GEN) 6668420Sjhb#endif 6768420Sjhb 6868420Sjhb#ifndef KTR_CPUMASK 6968420Sjhb#define KTR_CPUMASK (~0) 7068420Sjhb#endif 7168420Sjhb 7293503Sjake#ifndef KTR_TIME 7393503Sjake#define KTR_TIME get_cyclecount() 7468420Sjhb#endif 7568420Sjhb 7693503Sjake#ifndef KTR_CPU 7793503Sjake#define KTR_CPU PCPU_GET(cpuid) 7870705Sjhb#endif 7970705Sjhb 8070705SjhbSYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options"); 8170705Sjhb 8277843Speterint ktr_cpumask = KTR_CPUMASK; 8377900SpeterTUNABLE_INT("debug.ktr.cpumask", &ktr_cpumask); 8470705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, cpumask, CTLFLAG_RW, &ktr_cpumask, 0, ""); 8565556Sjasone 8677843Speterint ktr_mask = KTR_MASK; 8777900SpeterTUNABLE_INT("debug.ktr.mask", &ktr_mask); 8870705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, mask, CTLFLAG_RW, &ktr_mask, 0, ""); 8965556Sjasone 9065556Sjasoneint ktr_entries = KTR_ENTRIES; 9170705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, ""); 9265556Sjasone 9393503Sjakeint ktr_version = KTR_VERSION; 9493503SjakeSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, ""); 9593503Sjake 9665556Sjasonevolatile int ktr_idx = 0; 9765556Sjasonestruct ktr_entry ktr_buf[KTR_ENTRIES]; 9868420Sjhb 9993503Sjake#ifdef KTR_VERBOSE 10093503Sjakeint ktr_verbose = KTR_VERBOSE; 10177900SpeterTUNABLE_INT("debug.ktr.verbose", &ktr_verbose); 10270705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, ""); 10393503Sjake#endif 10468420Sjhb 105103787Sjeff#ifdef KTR_ALQ 106103787Sjeffstruct alq *ktr_alq; 107103787Sjeffchar ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out"; 108103787Sjeffint ktr_alq_cnt = 0; 109103787Sjeffint ktr_alq_depth = KTR_ENTRIES; 110103787Sjeffint ktr_alq_enabled = 0; 111103787Sjeffint ktr_alq_failed = 0; 112103787Sjeffint ktr_alq_max = 0; 113103787Sjeff 114103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0, 115103787Sjeff "Maximum number of entries to write"); 116103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0, 117103787Sjeff "Current number of written entries"); 118103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0, 119103787Sjeff "Number of times we overran the buffer"); 120103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0, 121103787Sjeff "Number of items in the write buffer"); 122103787SjeffSYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file, 123103787Sjeff sizeof(ktr_alq_file), "KTR logging file"); 124103787Sjeff 125103787Sjeffstatic int 126103787Sjeffsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS) 127103787Sjeff{ 128103787Sjeff int error; 129103787Sjeff int enable; 130103787Sjeff 131103787Sjeff enable = ktr_alq_enabled; 132103787Sjeff 133103787Sjeff error = sysctl_handle_int(oidp, &enable, 0, req); 134103787Sjeff if (error || !req->newptr) 135103787Sjeff return (error); 136103787Sjeff 137103787Sjeff if (enable) { 138103787Sjeff if (ktr_alq_enabled) 139103787Sjeff return (0); 140103787Sjeff error = suser(curthread); 141103787Sjeff if (error) 142103787Sjeff return (error); 143103787Sjeff error = alq_open(&ktr_alq, (const char *)ktr_alq_file, 144103787Sjeff sizeof(struct ktr_entry), ktr_alq_depth); 145103787Sjeff if (error == 0) { 146103787Sjeff ktr_mask &= ~KTR_ALQ_MASK; 147103787Sjeff ktr_alq_cnt = 0; 148103787Sjeff ktr_alq_failed = 0; 149103787Sjeff ktr_alq_enabled = 1; 150103787Sjeff } 151103787Sjeff } else { 152103787Sjeff if (ktr_alq_enabled == 0) 153103787Sjeff return (0); 154103787Sjeff ktr_alq_enabled = 0; 155103787Sjeff alq_close(ktr_alq); 156103787Sjeff ktr_alq = NULL; 157103787Sjeff } 158103787Sjeff 159103787Sjeff return (error); 160103787Sjeff} 161103787SjeffSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable, 162103787Sjeff CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable, 163103787Sjeff "I", "Enable KTR logging"); 164103787Sjeff#endif 165103787Sjeff 16668420Sjhbvoid 16793503Sjakektr_tracepoint(u_int mask, const char *file, int line, const char *format, 16893503Sjake u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5, 16993503Sjake u_long arg6) 17068420Sjhb{ 17168420Sjhb struct ktr_entry *entry; 172103787Sjeff#ifdef KTR_ALQ 173103787Sjeff struct ale *ale = NULL; 174103787Sjeff#else 17574903Sjhb int newindex, saveindex; 176103787Sjeff#endif 177103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 17887793Sjhb struct thread *td; 17993503Sjake#endif 18091904Sjhb int cpu; 18168420Sjhb 18269880Sjhb if (panicstr) 18369880Sjhb return; 18468420Sjhb if ((ktr_mask & mask) == 0) 18568420Sjhb return; 18693503Sjake cpu = KTR_CPU; 18793503Sjake if (((1 << cpu) & ktr_cpumask) == 0) 18893503Sjake return; 189103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 19087793Sjhb td = curthread; 19187793Sjhb if (td->td_inktr) 19287793Sjhb return; 19387793Sjhb td->td_inktr++; 19493503Sjake#endif 195103787Sjeff#ifdef KTR_ALQ 196103787Sjeff if (ktr_alq_enabled && 197103787Sjeff td->td_critnest == 0 && 198103995Sjeff (td->td_kse->ke_flags & KEF_IDLEKSE) == 0 && 199103995Sjeff td != ald_thread) { 200103787Sjeff if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max) 201103787Sjeff goto done; 202103787Sjeff if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) { 203103787Sjeff ktr_alq_failed++; 204103787Sjeff goto done; 205103787Sjeff } 206103787Sjeff ktr_alq_cnt++; 207103787Sjeff entry = (struct ktr_entry *)ale->ae_data; 208103787Sjeff } else 209103787Sjeff goto done; 210103787Sjeff#else 21168420Sjhb do { 21268420Sjhb saveindex = ktr_idx; 21368420Sjhb newindex = (saveindex + 1) & (KTR_ENTRIES - 1); 21468420Sjhb } while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0); 21568420Sjhb entry = &ktr_buf[saveindex]; 216103787Sjeff#endif 21793503Sjake entry->ktr_timestamp = KTR_TIME; 21891904Sjhb entry->ktr_cpu = cpu; 21993503Sjake entry->ktr_file = file; 22068420Sjhb entry->ktr_line = line; 22193503Sjake#ifdef KTR_VERBOSE 22268420Sjhb if (ktr_verbose) { 22368782Sjhb#ifdef SMP 22493503Sjake printf("cpu%d ", cpu); 22568782Sjhb#endif 22693503Sjake if (ktr_verbose > 1) { 22793503Sjake printf("%s.%d\t", entry->ktr_file, 22893503Sjake entry->ktr_line); 22993503Sjake } 23093503Sjake printf(format, arg1, arg2, arg3, arg4, arg5, arg6); 23168420Sjhb printf("\n"); 23268420Sjhb } 23393503Sjake#endif 23468420Sjhb entry->ktr_desc = format; 23593503Sjake entry->ktr_parms[0] = arg1; 23693503Sjake entry->ktr_parms[1] = arg2; 23793503Sjake entry->ktr_parms[2] = arg3; 23893503Sjake entry->ktr_parms[3] = arg4; 23993503Sjake entry->ktr_parms[4] = arg5; 24093503Sjake entry->ktr_parms[5] = arg6; 241103787Sjeff#ifdef KTR_ALQ 242103787Sjeff if (ale) 243103787Sjeff alq_post(ktr_alq, ale); 244103787Sjeffdone: 245103787Sjeff#endif 246103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 24793503Sjake td->td_inktr--; 24868420Sjhb#endif 24968420Sjhb} 25070035Sjhb 25170035Sjhb#ifdef DDB 25270035Sjhb 25370035Sjhbstruct tstate { 25470035Sjhb int cur; 25570035Sjhb int first; 25670035Sjhb}; 25770035Sjhbstatic struct tstate tstate; 25870035Sjhbstatic int db_ktr_verbose; 25970035Sjhbstatic int db_mach_vtrace(void); 26070035Sjhb 26172755Sjhb#define NUM_LINES_PER_PAGE 18 26272755Sjhb 26372755SjhbDB_SHOW_COMMAND(ktr, db_ktr_all) 26470035Sjhb{ 26572755Sjhb int c, lines; 26670035Sjhb 26772755Sjhb lines = NUM_LINES_PER_PAGE; 26870035Sjhb tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1); 26970035Sjhb tstate.first = -1; 27070035Sjhb if (strcmp(modif, "v") == 0) 27170035Sjhb db_ktr_verbose = 1; 27270035Sjhb else 27370035Sjhb db_ktr_verbose = 0; 27472755Sjhb while (db_mach_vtrace()) 27572755Sjhb if (--lines == 0) { 27672755Sjhb db_printf("--More--"); 27772755Sjhb c = cngetc(); 27872755Sjhb db_printf("\r"); 27972755Sjhb switch (c) { 28072755Sjhb case '\n': /* one more line */ 28172755Sjhb lines = 1; 28272755Sjhb break; 28372755Sjhb case ' ': /* one more page */ 28472755Sjhb lines = NUM_LINES_PER_PAGE; 28572755Sjhb break; 28672755Sjhb default: 28772755Sjhb db_printf("\n"); 28872755Sjhb return; 28972755Sjhb } 29072755Sjhb } 29170035Sjhb} 29270035Sjhb 29370035Sjhbstatic int 29470035Sjhbdb_mach_vtrace(void) 29570035Sjhb{ 29670035Sjhb struct ktr_entry *kp; 29770035Sjhb 29870035Sjhb if (tstate.cur == tstate.first) { 29970035Sjhb db_printf("--- End of trace buffer ---\n"); 30070035Sjhb return (0); 30170035Sjhb } 30270035Sjhb kp = &ktr_buf[tstate.cur]; 30370035Sjhb 30470035Sjhb /* Skip over unused entries. */ 30572755Sjhb if (kp->ktr_desc == NULL) { 30672755Sjhb db_printf("--- End of trace buffer ---\n"); 30772755Sjhb return (0); 30872755Sjhb } 30972755Sjhb db_printf("%d: ", tstate.cur); 31070035Sjhb#ifdef SMP 31172755Sjhb db_printf("cpu%d ", kp->ktr_cpu); 31270035Sjhb#endif 31393503Sjake if (db_ktr_verbose) { 31493503Sjake db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp, 31593503Sjake kp->ktr_file, kp->ktr_line); 31693503Sjake } 31793503Sjake db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1], 31893503Sjake kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4], 31993503Sjake kp->ktr_parms[5]); 32072755Sjhb db_printf("\n"); 32170035Sjhb 32270035Sjhb if (tstate.first == -1) 32370035Sjhb tstate.first = tstate.cur; 32470035Sjhb 32570035Sjhb if (--tstate.cur < 0) 32670035Sjhb tstate.cur = KTR_ENTRIES - 1; 32770035Sjhb 32870035Sjhb return (1); 32970035Sjhb} 33070035Sjhb 33170035Sjhb#endif /* DDB */ 332