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