kern_ktr.c revision 206632
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 206632 2010-04-14 21:42:29Z julian $"); 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 58160312Sjhb#ifdef DDB 5970035Sjhb#include <ddb/ddb.h> 60160312Sjhb#include <ddb/db_output.h> 61160312Sjhb#endif 6270035Sjhb 6378784Sjhb#ifndef KTR_ENTRIES 6478784Sjhb#define KTR_ENTRIES 1024 6578784Sjhb#endif 6678784Sjhb 6768420Sjhb#ifndef KTR_MASK 6868420Sjhb#define KTR_MASK (KTR_GEN) 6968420Sjhb#endif 7068420Sjhb 7168420Sjhb#ifndef KTR_CPUMASK 7268420Sjhb#define KTR_CPUMASK (~0) 7368420Sjhb#endif 7468420Sjhb 7593503Sjake#ifndef KTR_TIME 7693503Sjake#define KTR_TIME get_cyclecount() 7768420Sjhb#endif 7868420Sjhb 7993503Sjake#ifndef KTR_CPU 8093503Sjake#define KTR_CPU PCPU_GET(cpuid) 8170705Sjhb#endif 8270705Sjhb 8370705SjhbSYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options"); 8470705Sjhb 8577843Speterint ktr_cpumask = KTR_CPUMASK; 8677900SpeterTUNABLE_INT("debug.ktr.cpumask", &ktr_cpumask); 87205017SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, cpumask, CTLFLAG_RW, 88205017Sjhb &ktr_cpumask, 0, "Bitmask of CPUs on which KTR logging is enabled"); 8965556Sjasone 9077843Speterint ktr_mask = KTR_MASK; 9177900SpeterTUNABLE_INT("debug.ktr.mask", &ktr_mask); 92205017SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, mask, CTLFLAG_RW, 93205017Sjhb &ktr_mask, 0, "Bitmask of KTR event classes for which logging is enabled"); 9465556Sjasone 95132583Srwatsonint ktr_compile = KTR_COMPILE; 96205017SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, compile, CTLFLAG_RD, 97205017Sjhb &ktr_compile, 0, "Bitmask of KTR event classes compiled into the kernel"); 98132583Srwatson 9965556Sjasoneint ktr_entries = KTR_ENTRIES; 100205017SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, 101205017Sjhb &ktr_entries, 0, "Number of entries in the KTR buffer"); 10265556Sjasone 10393503Sjakeint ktr_version = KTR_VERSION; 104205017SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, 105205017Sjhb &ktr_version, 0, "Version of the KTR interface"); 10693503Sjake 10765556Sjasonevolatile int ktr_idx = 0; 10865556Sjasonestruct ktr_entry ktr_buf[KTR_ENTRIES]; 10968420Sjhb 110154933Sjhbstatic int 111154933Sjhbsysctl_debug_ktr_clear(SYSCTL_HANDLER_ARGS) 112154933Sjhb{ 113154933Sjhb int clear, error; 114154933Sjhb 115154933Sjhb clear = 0; 116154933Sjhb error = sysctl_handle_int(oidp, &clear, 0, req); 117154933Sjhb if (error || !req->newptr) 118154933Sjhb return (error); 119154933Sjhb 120154933Sjhb if (clear) { 121154933Sjhb bzero(ktr_buf, sizeof(ktr_buf)); 122154933Sjhb ktr_idx = 0; 123154933Sjhb } 124154933Sjhb 125154933Sjhb return (error); 126154933Sjhb} 127154933SjhbSYSCTL_PROC(_debug_ktr, OID_AUTO, clear, CTLTYPE_INT|CTLFLAG_RW, 0, 0, 128154933Sjhb sysctl_debug_ktr_clear, "I", "Clear KTR Buffer"); 129154933Sjhb 13093503Sjake#ifdef KTR_VERBOSE 13193503Sjakeint ktr_verbose = KTR_VERBOSE; 13277900SpeterTUNABLE_INT("debug.ktr.verbose", &ktr_verbose); 13370705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, ""); 13493503Sjake#endif 13568420Sjhb 136103787Sjeff#ifdef KTR_ALQ 137103787Sjeffstruct alq *ktr_alq; 138103787Sjeffchar ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out"; 139103787Sjeffint ktr_alq_cnt = 0; 140103787Sjeffint ktr_alq_depth = KTR_ENTRIES; 141103787Sjeffint ktr_alq_enabled = 0; 142103787Sjeffint ktr_alq_failed = 0; 143103787Sjeffint ktr_alq_max = 0; 144103787Sjeff 145103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0, 146103787Sjeff "Maximum number of entries to write"); 147103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0, 148103787Sjeff "Current number of written entries"); 149103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0, 150103787Sjeff "Number of times we overran the buffer"); 151103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0, 152103787Sjeff "Number of items in the write buffer"); 153103787SjeffSYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file, 154103787Sjeff sizeof(ktr_alq_file), "KTR logging file"); 155103787Sjeff 156103787Sjeffstatic int 157103787Sjeffsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS) 158103787Sjeff{ 159103787Sjeff int error; 160103787Sjeff int enable; 161103787Sjeff 162103787Sjeff enable = ktr_alq_enabled; 163103787Sjeff 164154940Sjhb error = sysctl_handle_int(oidp, &enable, 0, req); 165154940Sjhb if (error || !req->newptr) 166154940Sjhb return (error); 167103787Sjeff 168103787Sjeff if (enable) { 169103787Sjeff if (ktr_alq_enabled) 170103787Sjeff return (0); 171116697Srwatson error = alq_open(&ktr_alq, (const char *)ktr_alq_file, 172145142Srwatson req->td->td_ucred, ALQ_DEFAULT_CMODE, 173145142Srwatson sizeof(struct ktr_entry), ktr_alq_depth); 174103787Sjeff if (error == 0) { 175103787Sjeff ktr_alq_cnt = 0; 176103787Sjeff ktr_alq_failed = 0; 177103787Sjeff ktr_alq_enabled = 1; 178103787Sjeff } 179103787Sjeff } else { 180103787Sjeff if (ktr_alq_enabled == 0) 181103787Sjeff return (0); 182103787Sjeff ktr_alq_enabled = 0; 183103787Sjeff alq_close(ktr_alq); 184103787Sjeff ktr_alq = NULL; 185103787Sjeff } 186103787Sjeff 187103787Sjeff return (error); 188103787Sjeff} 189103787SjeffSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable, 190103787Sjeff CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable, 191103787Sjeff "I", "Enable KTR logging"); 192103787Sjeff#endif 193103787Sjeff 19468420Sjhbvoid 19593503Sjakektr_tracepoint(u_int mask, const char *file, int line, const char *format, 19693503Sjake u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5, 19793503Sjake u_long arg6) 19868420Sjhb{ 19968420Sjhb struct ktr_entry *entry; 200103787Sjeff#ifdef KTR_ALQ 201103787Sjeff struct ale *ale = NULL; 202206632Sjulian#endif 20374903Sjhb int newindex, saveindex; 204103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 20587793Sjhb struct thread *td; 20693503Sjake#endif 20791904Sjhb int cpu; 20868420Sjhb 20969880Sjhb if (panicstr) 21069880Sjhb return; 21168420Sjhb if ((ktr_mask & mask) == 0) 21268420Sjhb return; 21393503Sjake cpu = KTR_CPU; 21493503Sjake if (((1 << cpu) & ktr_cpumask) == 0) 21593503Sjake return; 216103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 21787793Sjhb td = curthread; 218116101Sjhb if (td->td_pflags & TDP_INKTR) 21987793Sjhb return; 220116101Sjhb td->td_pflags |= TDP_INKTR; 22193503Sjake#endif 222103787Sjeff#ifdef KTR_ALQ 223206632Sjulian if (ktr_alq_enabled) { 224206632Sjulian if (td->td_critnest == 0 && 225206632Sjulian (td->td_flags & TDF_IDLETD) == 0 && 226206632Sjulian td != ald_thread) { 227206632Sjulian if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max) 228206632Sjulian goto done; 229206632Sjulian if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) { 230206632Sjulian ktr_alq_failed++; 231206632Sjulian goto done; 232206632Sjulian } 233206632Sjulian ktr_alq_cnt++; 234206632Sjulian entry = (struct ktr_entry *)ale->ae_data; 235206632Sjulian } else { 236103787Sjeff goto done; 237103787Sjeff } 238103787Sjeff } else 239103787Sjeff#endif 240206632Sjulian { 241206632Sjulian do { 242206632Sjulian saveindex = ktr_idx; 243206632Sjulian newindex = (saveindex + 1) & (KTR_ENTRIES - 1); 244206632Sjulian } while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0); 245206632Sjulian entry = &ktr_buf[saveindex]; 246206632Sjulian } 24793503Sjake entry->ktr_timestamp = KTR_TIME; 24891904Sjhb entry->ktr_cpu = cpu; 249147278Sjeff entry->ktr_thread = curthread; 250112105Sjhb if (file != NULL) 251112105Sjhb while (strncmp(file, "../", 3) == 0) 252112105Sjhb file += 3; 25393503Sjake entry->ktr_file = file; 25468420Sjhb entry->ktr_line = line; 25593503Sjake#ifdef KTR_VERBOSE 25668420Sjhb if (ktr_verbose) { 25768782Sjhb#ifdef SMP 25893503Sjake printf("cpu%d ", cpu); 25968782Sjhb#endif 26093503Sjake if (ktr_verbose > 1) { 26193503Sjake printf("%s.%d\t", entry->ktr_file, 26293503Sjake entry->ktr_line); 26393503Sjake } 26493503Sjake printf(format, arg1, arg2, arg3, arg4, arg5, arg6); 26568420Sjhb printf("\n"); 26668420Sjhb } 26793503Sjake#endif 26868420Sjhb entry->ktr_desc = format; 26993503Sjake entry->ktr_parms[0] = arg1; 27093503Sjake entry->ktr_parms[1] = arg2; 27193503Sjake entry->ktr_parms[2] = arg3; 27293503Sjake entry->ktr_parms[3] = arg4; 27393503Sjake entry->ktr_parms[4] = arg5; 27493503Sjake entry->ktr_parms[5] = arg6; 275103787Sjeff#ifdef KTR_ALQ 276206632Sjulian if (ktr_alq_enabled && ale) 277103787Sjeff alq_post(ktr_alq, ale); 278103787Sjeffdone: 279103787Sjeff#endif 280103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ) 281116101Sjhb td->td_pflags &= ~TDP_INKTR; 28268420Sjhb#endif 28368420Sjhb} 28470035Sjhb 28570035Sjhb#ifdef DDB 28670035Sjhb 28770035Sjhbstruct tstate { 28870035Sjhb int cur; 28970035Sjhb int first; 29070035Sjhb}; 29170035Sjhbstatic struct tstate tstate; 29270035Sjhbstatic int db_ktr_verbose; 29370035Sjhbstatic int db_mach_vtrace(void); 29470035Sjhb 29572755SjhbDB_SHOW_COMMAND(ktr, db_ktr_all) 29670035Sjhb{ 297118269Sjhb 29870035Sjhb tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1); 29970035Sjhb tstate.first = -1; 300206632Sjulian db_ktr_verbose = 0; 301206632Sjulian db_ktr_verbose |= (index(modif, 'v') != NULL) ? 2 : 0; 302206632Sjulian db_ktr_verbose |= (index(modif, 'V') != NULL) ? 1 : 0; /* just timestap please */ 303160312Sjhb if (index(modif, 'a') != NULL) { 304160312Sjhb db_disable_pager(); 305118269Sjhb while (cncheckc() != -1) 306118269Sjhb if (db_mach_vtrace() == 0) 30772755Sjhb break; 308118269Sjhb } else { 309160312Sjhb while (!db_pager_quit) 310118269Sjhb if (db_mach_vtrace() == 0) 31172755Sjhb break; 312118269Sjhb } 31370035Sjhb} 31470035Sjhb 31570035Sjhbstatic int 31670035Sjhbdb_mach_vtrace(void) 31770035Sjhb{ 31870035Sjhb struct ktr_entry *kp; 31970035Sjhb 32070035Sjhb if (tstate.cur == tstate.first) { 32170035Sjhb db_printf("--- End of trace buffer ---\n"); 32270035Sjhb return (0); 32370035Sjhb } 32470035Sjhb kp = &ktr_buf[tstate.cur]; 32570035Sjhb 32670035Sjhb /* Skip over unused entries. */ 32772755Sjhb if (kp->ktr_desc == NULL) { 32872755Sjhb db_printf("--- End of trace buffer ---\n"); 32972755Sjhb return (0); 33072755Sjhb } 331147278Sjeff db_printf("%d (%p", tstate.cur, kp->ktr_thread); 33270035Sjhb#ifdef SMP 333147278Sjeff db_printf(":cpu%d", kp->ktr_cpu); 33470035Sjhb#endif 335147278Sjeff db_printf(")"); 336206632Sjulian if (db_ktr_verbose >= 1) { 337206632Sjulian db_printf(" %10.10lld", (long long)kp->ktr_timestamp); 33893503Sjake } 339206632Sjulian if (db_ktr_verbose >= 2) { 340206632Sjulian db_printf(" %s.%d", kp->ktr_file, kp->ktr_line); 341206632Sjulian } 342147278Sjeff db_printf(": "); 34393503Sjake db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1], 34493503Sjake kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4], 34593503Sjake kp->ktr_parms[5]); 34672755Sjhb db_printf("\n"); 34770035Sjhb 34870035Sjhb if (tstate.first == -1) 34970035Sjhb tstate.first = tstate.cur; 35070035Sjhb 35170035Sjhb if (--tstate.cur < 0) 35270035Sjhb tstate.cur = KTR_ENTRIES - 1; 35370035Sjhb 35470035Sjhb return (1); 35570035Sjhb} 35670035Sjhb 35770035Sjhb#endif /* DDB */ 358