kern_ktr.c revision 119936
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 119936 2003-09-10 01:09:32Z jhb $");
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{
270118362Sjhb	int quit;
271118269Sjhb
272118269Sjhb	quit = 0;
27370035Sjhb	tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1);
27470035Sjhb	tstate.first = -1;
27570035Sjhb	if (strcmp(modif, "v") == 0)
27670035Sjhb		db_ktr_verbose = 1;
27770035Sjhb	else
27870035Sjhb		db_ktr_verbose = 0;
279118269Sjhb	if (strcmp(modif, "a") == 0) {
280118269Sjhb		while (cncheckc() != -1)
281118269Sjhb			if (db_mach_vtrace() == 0)
28272755Sjhb				break;
283118269Sjhb	} else {
284118269Sjhb		db_setup_paging(db_simple_pager, &quit, DB_LINES_PER_PAGE);
285118269Sjhb		while (!quit)
286118269Sjhb			if (db_mach_vtrace() == 0)
28772755Sjhb				break;
288118269Sjhb	}
28970035Sjhb}
29070035Sjhb
29170035Sjhbstatic int
29270035Sjhbdb_mach_vtrace(void)
29370035Sjhb{
29470035Sjhb	struct ktr_entry	*kp;
29570035Sjhb
29670035Sjhb	if (tstate.cur == tstate.first) {
29770035Sjhb		db_printf("--- End of trace buffer ---\n");
29870035Sjhb		return (0);
29970035Sjhb	}
30070035Sjhb	kp = &ktr_buf[tstate.cur];
30170035Sjhb
30270035Sjhb	/* Skip over unused entries. */
30372755Sjhb	if (kp->ktr_desc == NULL) {
30472755Sjhb		db_printf("--- End of trace buffer ---\n");
30572755Sjhb		return (0);
30672755Sjhb	}
30772755Sjhb	db_printf("%d: ", tstate.cur);
30870035Sjhb#ifdef SMP
30972755Sjhb	db_printf("cpu%d ", kp->ktr_cpu);
31070035Sjhb#endif
31193503Sjake	if (db_ktr_verbose) {
31293503Sjake		db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp,
31393503Sjake		    kp->ktr_file, kp->ktr_line);
31493503Sjake	}
31593503Sjake	db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1],
31693503Sjake	    kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4],
31793503Sjake	    kp->ktr_parms[5]);
31872755Sjhb	db_printf("\n");
31970035Sjhb
32070035Sjhb	if (tstate.first == -1)
32170035Sjhb		tstate.first = tstate.cur;
32270035Sjhb
32370035Sjhb	if (--tstate.cur < 0)
32470035Sjhb		tstate.cur = KTR_ENTRIES - 1;
32570035Sjhb
32670035Sjhb	return (1);
32770035Sjhb}
32870035Sjhb
32970035Sjhb#endif	/* DDB */
330