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