kern_ktr.c revision 116697
1234353Sdim/*
2198090Srdivacky * Copyright (c) 2000
3198090Srdivacky *	John Baldwin <jhb@FreeBSD.org>.  All rights reserved.
4198090Srdivacky *
5198090Srdivacky * Redistribution and use in source and binary forms, with or without
6198090Srdivacky * modification, are permitted provided that the following conditions
7198090Srdivacky * are met:
8198090Srdivacky * 1. Redistributions of source code must retain the above copyright
9198090Srdivacky *    notice, this list of conditions and the following disclaimer.
10198090Srdivacky * 2. Redistributions in binary form must reproduce the above copyright
11198090Srdivacky *    notice, this list of conditions and the following disclaimer in the
12198090Srdivacky *    documentation and/or other materials provided with the distribution.
13198090Srdivacky * 4. Neither the name of the author nor the names of any co-contributors
14198090Srdivacky *    may be used to endorse or promote products derived from this software
15249423Sdim *    without specific prior written permission.
16239462Sdim *
17239462Sdim * THIS SOFTWARE IS PROVIDED BY JOHN BALDWIN AND CONTRIBUTORS ``AS IS'' AND
18239462Sdim * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
19239462Sdim * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
20239462Sdim * ARE DISCLAIMED.  IN NO EVENT SHALL JOHN BALDWIN OR THE VOICES IN HIS HEAD
21249423Sdim * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
22249423Sdim * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
23249423Sdim * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
24249423Sdim * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
25249423Sdim * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
26249423Sdim * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF
27249423Sdim * THE POSSIBILITY OF SUCH DAMAGE.
28249423Sdim */
29249423Sdim
30239462Sdim/*
31239462Sdim * This module holds the global variables used by KTR and the ktr_tracepoint()
32239462Sdim * function that does the actual tracing.
33218893Sdim */
34280031Sdim
35239462Sdim#include <sys/cdefs.h>
36198090Srdivacky__FBSDID("$FreeBSD: head/sys/kern/kern_ktr.c 116697 2003-06-22 22:28:56Z rwatson $");
37198090Srdivacky
38218893Sdim#include "opt_ddb.h"
39198090Srdivacky#include "opt_ktr.h"
40198090Srdivacky#include "opt_alq.h"
41276479Sdim
42276479Sdim#include <sys/param.h>
43198090Srdivacky#include <sys/alq.h>
44198090Srdivacky#include <sys/cons.h>
45198090Srdivacky#include <sys/kernel.h>
46198090Srdivacky#include <sys/ktr.h>
47261991Sdim#include <sys/libkern.h>
48288943Sdim#include <sys/proc.h>
49288943Sdim#include <sys/sysctl.h>
50261991Sdim#include <sys/systm.h>
51261991Sdim#include <sys/time.h>
52261991Sdim
53296417Sdim#include <machine/cpu.h>
54261991Sdim#ifdef __sparc64__
55261991Sdim#include <machine/ktr.h>
56261991Sdim#endif
57261991Sdim
58261991Sdim
59261991Sdim#include <ddb/ddb.h>
60261991Sdim
61261991Sdim#ifndef KTR_ENTRIES
62198090Srdivacky#define	KTR_ENTRIES	1024
63261991Sdim#endif
64261991Sdim
65288943Sdim#ifndef KTR_MASK
66276479Sdim#define	KTR_MASK	(KTR_GEN)
67276479Sdim#endif
68198090Srdivacky
69276479Sdim#ifndef KTR_CPUMASK
70276479Sdim#define	KTR_CPUMASK	(~0)
71261991Sdim#endif
72261991Sdim
73261991Sdim#ifndef KTR_TIME
74261991Sdim#define	KTR_TIME	get_cyclecount()
75261991Sdim#endif
76261991Sdim
77261991Sdim#ifndef KTR_CPU
78261991Sdim#define	KTR_CPU		PCPU_GET(cpuid)
79261991Sdim#endif
80261991Sdim
81261991SdimSYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options");
82198090Srdivacky
83198090Srdivackyint	ktr_cpumask = KTR_CPUMASK;
84234353SdimTUNABLE_INT("debug.ktr.cpumask", &ktr_cpumask);
85288943SdimSYSCTL_INT(_debug_ktr, OID_AUTO, cpumask, CTLFLAG_RW, &ktr_cpumask, 0, "");
86288943Sdim
87198090Srdivackyint	ktr_mask = KTR_MASK;
88234353SdimTUNABLE_INT("debug.ktr.mask", &ktr_mask);
89288943SdimSYSCTL_INT(_debug_ktr, OID_AUTO, mask, CTLFLAG_RW, &ktr_mask, 0, "");
90198090Srdivacky
91198090Srdivackyint	ktr_entries = KTR_ENTRIES;
92234353SdimSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, "");
93198090Srdivacky
94198090Srdivackyint	ktr_version = KTR_VERSION;
95224145SdimSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, "");
96224145Sdim
97288943Sdimvolatile int	ktr_idx = 0;
98288943Sdimstruct	ktr_entry ktr_buf[KTR_ENTRIES];
99288943Sdim
100288943Sdim#ifdef KTR_VERBOSE
101288943Sdimint	ktr_verbose = KTR_VERBOSE;
102288943SdimTUNABLE_INT("debug.ktr.verbose", &ktr_verbose);
103288943SdimSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, "");
104288943Sdim#endif
105280031Sdim
106261991Sdim#ifdef KTR_ALQ
107261991Sdimstruct alq *ktr_alq;
108276479Sdimchar	ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out";
109261991Sdimint	ktr_alq_cnt = 0;
110261991Sdimint	ktr_alq_depth = KTR_ENTRIES;
111276479Sdimint	ktr_alq_enabled = 0;
112198090Srdivackyint	ktr_alq_failed = 0;
113210299Sedint	ktr_alq_max = 0;
114210299Sed
115296417SdimSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0,
116296417Sdim    "Maximum number of entries to write");
117198090SrdivackySYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0,
118203954Srdivacky    "Current number of written entries");
119226633SdimSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0,
120276479Sdim    "Number of times we overran the buffer");
121198090SrdivackySYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0,
122198090Srdivacky    "Number of items in the write buffer");
123198090SrdivackySYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file,
124198090Srdivacky    sizeof(ktr_alq_file), "KTR logging file");
125204792Srdivacky
126204792Srdivackystatic int
127234353Sdimsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS)
128234353Sdim{
129234353Sdim	int error;
130234353Sdim	int enable;
131234353Sdim
132234353Sdim	enable = ktr_alq_enabled;
133234353Sdim
134234353Sdim        error = sysctl_handle_int(oidp, &enable, 0, req);
135288943Sdim        if (error || !req->newptr)
136288943Sdim                return (error);
137234353Sdim
138234353Sdim	if (enable) {
139261991Sdim		if (ktr_alq_enabled)
140261991Sdim			return (0);
141261991Sdim		error = suser(curthread);
142204792Srdivacky		if (error)
143204792Srdivacky			return (error);
144198090Srdivacky		error = alq_open(&ktr_alq, (const char *)ktr_alq_file,
145198090Srdivacky		    req->td->td_ucred, sizeof(struct ktr_entry),
146234353Sdim		    ktr_alq_depth);
147280031Sdim		if (error == 0) {
148280031Sdim			ktr_mask &= ~KTR_ALQ_MASK;
149261991Sdim			ktr_alq_cnt = 0;
150198090Srdivacky			ktr_alq_failed = 0;
151198090Srdivacky			ktr_alq_enabled = 1;
152198090Srdivacky		}
153198090Srdivacky	} else {
154198090Srdivacky		if (ktr_alq_enabled == 0)
155234353Sdim			return (0);
156234353Sdim		ktr_alq_enabled = 0;
157234353Sdim		alq_close(ktr_alq);
158234353Sdim		ktr_alq = NULL;
159276479Sdim	}
160234353Sdim
161234353Sdim	return (error);
162234353Sdim}
163261991SdimSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable,
164261991Sdim    CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable,
165261991Sdim    "I", "Enable KTR logging");
166261991Sdim#endif
167234353Sdim
168234353Sdimvoid
169234353Sdimktr_tracepoint(u_int mask, const char *file, int line, const char *format,
170234353Sdim    u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5,
171234353Sdim    u_long arg6)
172234353Sdim{
173198090Srdivacky	struct ktr_entry *entry;
174198090Srdivacky#ifdef KTR_ALQ
175261991Sdim	struct ale *ale = NULL;
176261991Sdim#else
177198090Srdivacky	int newindex, saveindex;
178234353Sdim#endif
179234353Sdim#if defined(KTR_VERBOSE) || defined(KTR_ALQ)
180234353Sdim	struct thread *td;
181234353Sdim#endif
182296417Sdim	int cpu;
183296417Sdim
184234353Sdim	if (panicstr)
185234353Sdim		return;
186198090Srdivacky	if ((ktr_mask & mask) == 0)
187234353Sdim		return;
188198090Srdivacky	cpu = KTR_CPU;
189198090Srdivacky	if (((1 << cpu) & ktr_cpumask) == 0)
190226633Sdim		return;
191226633Sdim#if defined(KTR_VERBOSE) || defined(KTR_ALQ)
192261991Sdim	td = curthread;
193261991Sdim	if (td->td_pflags & TDP_INKTR)
194296417Sdim		return;
195226633Sdim	td->td_pflags |= TDP_INKTR;
196226633Sdim#endif
197226633Sdim#ifdef KTR_ALQ
198226633Sdim	if (ktr_alq_enabled &&
199288943Sdim	    td->td_critnest == 0 &&
200288943Sdim	    (td->td_flags & TDF_IDLETD) == 0 &&
201276479Sdim	    td != ald_thread) {
202296417Sdim		if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max)
203226633Sdim			goto done;
204226633Sdim		if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) {
205226633Sdim			ktr_alq_failed++;
206226633Sdim			goto done;
207296417Sdim		}
208296417Sdim		ktr_alq_cnt++;
209226633Sdim		entry = (struct ktr_entry *)ale->ae_data;
210234353Sdim	} else
211288943Sdim		goto done;
212288943Sdim#else
213234353Sdim	do {
214234353Sdim		saveindex = ktr_idx;
215288943Sdim		newindex = (saveindex + 1) & (KTR_ENTRIES - 1);
216288943Sdim	} while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0);
217226633Sdim	entry = &ktr_buf[saveindex];
218243830Sdim#endif
219234353Sdim	entry->ktr_timestamp = KTR_TIME;
220288943Sdim	entry->ktr_cpu = cpu;
221288943Sdim	if (file != NULL)
222226633Sdim		while (strncmp(file, "../", 3) == 0)
223226633Sdim			file += 3;
224234353Sdim	entry->ktr_file = file;
225226633Sdim	entry->ktr_line = line;
226226633Sdim#ifdef KTR_VERBOSE
227226633Sdim	if (ktr_verbose) {
228243830Sdim#ifdef SMP
229226633Sdim		printf("cpu%d ", cpu);
230288943Sdim#endif
231288943Sdim		if (ktr_verbose > 1) {
232288943Sdim			printf("%s.%d\t", entry->ktr_file,
233261991Sdim			    entry->ktr_line);
234261991Sdim		}
235261991Sdim		printf(format, arg1, arg2, arg3, arg4, arg5, arg6);
236226633Sdim		printf("\n");
237226633Sdim	}
238288943Sdim#endif
239288943Sdim	entry->ktr_desc = format;
240288943Sdim	entry->ktr_parms[0] = arg1;
241243830Sdim	entry->ktr_parms[1] = arg2;
242226633Sdim	entry->ktr_parms[2] = arg3;
243226633Sdim	entry->ktr_parms[3] = arg4;
244226633Sdim	entry->ktr_parms[4] = arg5;
245226633Sdim	entry->ktr_parms[5] = arg6;
246226633Sdim#ifdef KTR_ALQ
247226633Sdim	if (ale)
248226633Sdim		alq_post(ktr_alq, ale);
249226633Sdimdone:
250234353Sdim#endif
251226633Sdim#if defined(KTR_VERBOSE) || defined(KTR_ALQ)
252226633Sdim	td->td_pflags &= ~TDP_INKTR;
253226633Sdim#endif
254226633Sdim}
255296417Sdim
256226633Sdim#ifdef DDB
257296417Sdim
258296417Sdimstruct tstate {
259226633Sdim	int	cur;
260276479Sdim	int	first;
261276479Sdim};
262276479Sdimstatic	struct tstate tstate;
263296417Sdimstatic	int db_ktr_verbose;
264296417Sdimstatic	int db_mach_vtrace(void);
265296417Sdim
266226633Sdim#define	NUM_LINES_PER_PAGE	18
267276479Sdim
268296417SdimDB_SHOW_COMMAND(ktr, db_ktr_all)
269226633Sdim{
270226633Sdim	int	c, lines;
271226633Sdim	int	all = 0;
272226633Sdim
273226633Sdim	lines = NUM_LINES_PER_PAGE;
274234353Sdim	tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1);
275261991Sdim	tstate.first = -1;
276226633Sdim	if (strcmp(modif, "v") == 0)
277261991Sdim		db_ktr_verbose = 1;
278261991Sdim	else
279261991Sdim		db_ktr_verbose = 0;
280226633Sdim	if (strcmp(modif, "a") == 0)
281226633Sdim		all = 1;
282226633Sdim	while (db_mach_vtrace())
283296417Sdim		if (all) {
284261991Sdim			if (cncheckc() != -1)
285261991Sdim				return;
286226633Sdim		} else if (--lines == 0) {
287276479Sdim			db_printf("--More--");
288276479Sdim			c = cngetc();
289261991Sdim			db_printf("\r");
290226633Sdim			switch (c) {
291226633Sdim			case '\n':	/* one more line */
292226633Sdim				lines = 1;
293226633Sdim				break;
294226633Sdim			case ' ':	/* one more page */
295226633Sdim				lines = NUM_LINES_PER_PAGE;
296226633Sdim				break;
297226633Sdim			default:
298261991Sdim				db_printf("\n");
299276479Sdim				return;
300276479Sdim			}
301276479Sdim		}
302276479Sdim}
303226633Sdim
304226633Sdimstatic int
305226633Sdimdb_mach_vtrace(void)
306261991Sdim{
307226633Sdim	struct ktr_entry	*kp;
308226633Sdim
309226633Sdim	if (tstate.cur == tstate.first) {
310226633Sdim		db_printf("--- End of trace buffer ---\n");
311226633Sdim		return (0);
312226633Sdim	}
313226633Sdim	kp = &ktr_buf[tstate.cur];
314226633Sdim
315226633Sdim	/* Skip over unused entries. */
316226633Sdim	if (kp->ktr_desc == NULL) {
317226633Sdim		db_printf("--- End of trace buffer ---\n");
318226633Sdim		return (0);
319226633Sdim	}
320226633Sdim	db_printf("%d: ", tstate.cur);
321226633Sdim#ifdef SMP
322226633Sdim	db_printf("cpu%d ", kp->ktr_cpu);
323226633Sdim#endif
324226633Sdim	if (db_ktr_verbose) {
325226633Sdim		db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp,
326226633Sdim		    kp->ktr_file, kp->ktr_line);
327226633Sdim	}
328226633Sdim	db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1],
329234353Sdim	    kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4],
330261991Sdim	    kp->ktr_parms[5]);
331226633Sdim	db_printf("\n");
332234353Sdim
333226633Sdim	if (tstate.first == -1)
334226633Sdim		tstate.first = tstate.cur;
335226633Sdim
336226633Sdim	if (--tstate.cur < 0)
337226633Sdim		tstate.cur = KTR_ENTRIES - 1;
338226633Sdim
339226633Sdim	return (1);
340226633Sdim}
341234353Sdim
342226633Sdim#endif	/* DDB */
343226633Sdim