kern_ktr.c revision 103995
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 * $FreeBSD: head/sys/kern/kern_ktr.c 103995 2002-09-26 07:38:56Z jeff $
3065556Sjasone */
3165556Sjasone
3265556Sjasone/*
3368420Sjhb * This module holds the global variables used by KTR and the ktr_tracepoint()
3468420Sjhb * function that does the actual tracing.
3565556Sjasone */
3665556Sjasone
3770035Sjhb#include "opt_ddb.h"
3868420Sjhb#include "opt_ktr.h"
39103787Sjeff#include "opt_alq.h"
4068420Sjhb
4170035Sjhb#include <sys/param.h>
42103787Sjeff#include <sys/alq.h>
4370035Sjhb#include <sys/cons.h>
4470705Sjhb#include <sys/kernel.h>
4565556Sjasone#include <sys/ktr.h>
4668420Sjhb#include <sys/libkern.h>
4787793Sjhb#include <sys/proc.h>
4865556Sjasone#include <sys/sysctl.h>
4968420Sjhb#include <sys/systm.h>
5078784Sjhb#include <sys/time.h>
5165556Sjasone
5293503Sjake#include <machine/cpu.h>
5393950Sjake#ifdef __sparc64__
5493950Sjake#include <machine/ktr.h>
5593950Sjake#endif
5693503Sjake
57103787Sjeff
5870035Sjhb#include <ddb/ddb.h>
5970035Sjhb
6078784Sjhb#ifndef KTR_ENTRIES
6178784Sjhb#define	KTR_ENTRIES	1024
6278784Sjhb#endif
6378784Sjhb
6468420Sjhb#ifndef KTR_MASK
6568420Sjhb#define	KTR_MASK	(KTR_GEN)
6668420Sjhb#endif
6768420Sjhb
6868420Sjhb#ifndef KTR_CPUMASK
6968420Sjhb#define	KTR_CPUMASK	(~0)
7068420Sjhb#endif
7168420Sjhb
7293503Sjake#ifndef KTR_TIME
7393503Sjake#define	KTR_TIME	get_cyclecount()
7468420Sjhb#endif
7568420Sjhb
7693503Sjake#ifndef KTR_CPU
7793503Sjake#define	KTR_CPU		PCPU_GET(cpuid)
7870705Sjhb#endif
7970705Sjhb
8070705SjhbSYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RD, 0, "KTR options");
8170705Sjhb
8277843Speterint	ktr_cpumask = KTR_CPUMASK;
8377900SpeterTUNABLE_INT("debug.ktr.cpumask", &ktr_cpumask);
8470705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, cpumask, CTLFLAG_RW, &ktr_cpumask, 0, "");
8565556Sjasone
8677843Speterint	ktr_mask = KTR_MASK;
8777900SpeterTUNABLE_INT("debug.ktr.mask", &ktr_mask);
8870705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, mask, CTLFLAG_RW, &ktr_mask, 0, "");
8965556Sjasone
9065556Sjasoneint	ktr_entries = KTR_ENTRIES;
9170705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, "");
9265556Sjasone
9393503Sjakeint	ktr_version = KTR_VERSION;
9493503SjakeSYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, "");
9593503Sjake
9665556Sjasonevolatile int	ktr_idx = 0;
9765556Sjasonestruct	ktr_entry ktr_buf[KTR_ENTRIES];
9868420Sjhb
9993503Sjake#ifdef KTR_VERBOSE
10093503Sjakeint	ktr_verbose = KTR_VERBOSE;
10177900SpeterTUNABLE_INT("debug.ktr.verbose", &ktr_verbose);
10270705SjhbSYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, "");
10393503Sjake#endif
10468420Sjhb
105103787Sjeff#ifdef KTR_ALQ
106103787Sjeffstruct alq *ktr_alq;
107103787Sjeffchar	ktr_alq_file[MAXPATHLEN] = "/tmp/ktr.out";
108103787Sjeffint	ktr_alq_cnt = 0;
109103787Sjeffint	ktr_alq_depth = KTR_ENTRIES;
110103787Sjeffint	ktr_alq_enabled = 0;
111103787Sjeffint	ktr_alq_failed = 0;
112103787Sjeffint	ktr_alq_max = 0;
113103787Sjeff
114103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_max, CTLFLAG_RW, &ktr_alq_max, 0,
115103787Sjeff    "Maximum number of entries to write");
116103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_cnt, CTLFLAG_RD, &ktr_alq_cnt, 0,
117103787Sjeff    "Current number of written entries");
118103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_failed, CTLFLAG_RD, &ktr_alq_failed, 0,
119103787Sjeff    "Number of times we overran the buffer");
120103787SjeffSYSCTL_INT(_debug_ktr, OID_AUTO, alq_depth, CTLFLAG_RW, &ktr_alq_depth, 0,
121103787Sjeff    "Number of items in the write buffer");
122103787SjeffSYSCTL_STRING(_debug_ktr, OID_AUTO, alq_file, CTLFLAG_RW, ktr_alq_file,
123103787Sjeff    sizeof(ktr_alq_file), "KTR logging file");
124103787Sjeff
125103787Sjeffstatic int
126103787Sjeffsysctl_debug_ktr_alq_enable(SYSCTL_HANDLER_ARGS)
127103787Sjeff{
128103787Sjeff	int error;
129103787Sjeff	int enable;
130103787Sjeff
131103787Sjeff	enable = ktr_alq_enabled;
132103787Sjeff
133103787Sjeff        error = sysctl_handle_int(oidp, &enable, 0, req);
134103787Sjeff        if (error || !req->newptr)
135103787Sjeff                return (error);
136103787Sjeff
137103787Sjeff	if (enable) {
138103787Sjeff		if (ktr_alq_enabled)
139103787Sjeff			return (0);
140103787Sjeff		error = suser(curthread);
141103787Sjeff		if (error)
142103787Sjeff			return (error);
143103787Sjeff		error = alq_open(&ktr_alq, (const char *)ktr_alq_file,
144103787Sjeff		    sizeof(struct ktr_entry), ktr_alq_depth);
145103787Sjeff		if (error == 0) {
146103787Sjeff			ktr_mask &= ~KTR_ALQ_MASK;
147103787Sjeff			ktr_alq_cnt = 0;
148103787Sjeff			ktr_alq_failed = 0;
149103787Sjeff			ktr_alq_enabled = 1;
150103787Sjeff		}
151103787Sjeff	} else {
152103787Sjeff		if (ktr_alq_enabled == 0)
153103787Sjeff			return (0);
154103787Sjeff		ktr_alq_enabled = 0;
155103787Sjeff		alq_close(ktr_alq);
156103787Sjeff		ktr_alq = NULL;
157103787Sjeff	}
158103787Sjeff
159103787Sjeff	return (error);
160103787Sjeff}
161103787SjeffSYSCTL_PROC(_debug_ktr, OID_AUTO, alq_enable,
162103787Sjeff    CTLTYPE_INT|CTLFLAG_RW, 0, 0, sysctl_debug_ktr_alq_enable,
163103787Sjeff    "I", "Enable KTR logging");
164103787Sjeff#endif
165103787Sjeff
16668420Sjhbvoid
16793503Sjakektr_tracepoint(u_int mask, const char *file, int line, const char *format,
16893503Sjake    u_long arg1, u_long arg2, u_long arg3, u_long arg4, u_long arg5,
16993503Sjake    u_long arg6)
17068420Sjhb{
17168420Sjhb	struct ktr_entry *entry;
172103787Sjeff#ifdef KTR_ALQ
173103787Sjeff	struct ale *ale = NULL;
174103787Sjeff#else
17574903Sjhb	int newindex, saveindex;
176103787Sjeff#endif
177103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ)
17887793Sjhb	struct thread *td;
17993503Sjake#endif
18091904Sjhb	int cpu;
18168420Sjhb
18269880Sjhb	if (panicstr)
18369880Sjhb		return;
18468420Sjhb	if ((ktr_mask & mask) == 0)
18568420Sjhb		return;
18693503Sjake	cpu = KTR_CPU;
18793503Sjake	if (((1 << cpu) & ktr_cpumask) == 0)
18893503Sjake		return;
189103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ)
19087793Sjhb	td = curthread;
19187793Sjhb	if (td->td_inktr)
19287793Sjhb		return;
19387793Sjhb	td->td_inktr++;
19493503Sjake#endif
195103787Sjeff#ifdef KTR_ALQ
196103787Sjeff	if (ktr_alq_enabled &&
197103787Sjeff	    td->td_critnest == 0 &&
198103995Sjeff	    (td->td_kse->ke_flags & KEF_IDLEKSE) == 0 &&
199103995Sjeff	    td != ald_thread) {
200103787Sjeff		if (ktr_alq_max && ktr_alq_cnt > ktr_alq_max)
201103787Sjeff			goto done;
202103787Sjeff		if ((ale = alq_get(ktr_alq, ALQ_NOWAIT)) == NULL) {
203103787Sjeff			ktr_alq_failed++;
204103787Sjeff			goto done;
205103787Sjeff		}
206103787Sjeff		ktr_alq_cnt++;
207103787Sjeff		entry = (struct ktr_entry *)ale->ae_data;
208103787Sjeff	} else
209103787Sjeff		goto done;
210103787Sjeff#else
21168420Sjhb	do {
21268420Sjhb		saveindex = ktr_idx;
21368420Sjhb		newindex = (saveindex + 1) & (KTR_ENTRIES - 1);
21468420Sjhb	} while (atomic_cmpset_rel_int(&ktr_idx, saveindex, newindex) == 0);
21568420Sjhb	entry = &ktr_buf[saveindex];
216103787Sjeff#endif
21793503Sjake	entry->ktr_timestamp = KTR_TIME;
21891904Sjhb	entry->ktr_cpu = cpu;
21993503Sjake	entry->ktr_file = file;
22068420Sjhb	entry->ktr_line = line;
22193503Sjake#ifdef KTR_VERBOSE
22268420Sjhb	if (ktr_verbose) {
22368782Sjhb#ifdef SMP
22493503Sjake		printf("cpu%d ", cpu);
22568782Sjhb#endif
22693503Sjake		if (ktr_verbose > 1) {
22793503Sjake			printf("%s.%d\t", entry->ktr_file,
22893503Sjake			    entry->ktr_line);
22993503Sjake		}
23093503Sjake		printf(format, arg1, arg2, arg3, arg4, arg5, arg6);
23168420Sjhb		printf("\n");
23268420Sjhb	}
23393503Sjake#endif
23468420Sjhb	entry->ktr_desc = format;
23593503Sjake	entry->ktr_parms[0] = arg1;
23693503Sjake	entry->ktr_parms[1] = arg2;
23793503Sjake	entry->ktr_parms[2] = arg3;
23893503Sjake	entry->ktr_parms[3] = arg4;
23993503Sjake	entry->ktr_parms[4] = arg5;
24093503Sjake	entry->ktr_parms[5] = arg6;
241103787Sjeff#ifdef KTR_ALQ
242103787Sjeff	if (ale)
243103787Sjeff		alq_post(ktr_alq, ale);
244103787Sjeffdone:
245103787Sjeff#endif
246103787Sjeff#if defined(KTR_VERBOSE) || defined(KTR_ALQ)
24793503Sjake	td->td_inktr--;
24868420Sjhb#endif
24968420Sjhb}
25070035Sjhb
25170035Sjhb#ifdef DDB
25270035Sjhb
25370035Sjhbstruct tstate {
25470035Sjhb	int	cur;
25570035Sjhb	int	first;
25670035Sjhb};
25770035Sjhbstatic	struct tstate tstate;
25870035Sjhbstatic	int db_ktr_verbose;
25970035Sjhbstatic	int db_mach_vtrace(void);
26070035Sjhb
26172755Sjhb#define	NUM_LINES_PER_PAGE	18
26272755Sjhb
26372755SjhbDB_SHOW_COMMAND(ktr, db_ktr_all)
26470035Sjhb{
26572755Sjhb	int	c, lines;
26670035Sjhb
26772755Sjhb	lines = NUM_LINES_PER_PAGE;
26870035Sjhb	tstate.cur = (ktr_idx - 1) & (KTR_ENTRIES - 1);
26970035Sjhb	tstate.first = -1;
27070035Sjhb	if (strcmp(modif, "v") == 0)
27170035Sjhb		db_ktr_verbose = 1;
27270035Sjhb	else
27370035Sjhb		db_ktr_verbose = 0;
27472755Sjhb	while (db_mach_vtrace())
27572755Sjhb		if (--lines == 0) {
27672755Sjhb			db_printf("--More--");
27772755Sjhb			c = cngetc();
27872755Sjhb			db_printf("\r");
27972755Sjhb			switch (c) {
28072755Sjhb			case '\n':	/* one more line */
28172755Sjhb				lines = 1;
28272755Sjhb				break;
28372755Sjhb			case ' ':	/* one more page */
28472755Sjhb				lines = NUM_LINES_PER_PAGE;
28572755Sjhb				break;
28672755Sjhb			default:
28772755Sjhb				db_printf("\n");
28872755Sjhb				return;
28972755Sjhb			}
29072755Sjhb		}
29170035Sjhb}
29270035Sjhb
29370035Sjhbstatic int
29470035Sjhbdb_mach_vtrace(void)
29570035Sjhb{
29670035Sjhb	struct ktr_entry	*kp;
29770035Sjhb
29870035Sjhb	if (tstate.cur == tstate.first) {
29970035Sjhb		db_printf("--- End of trace buffer ---\n");
30070035Sjhb		return (0);
30170035Sjhb	}
30270035Sjhb	kp = &ktr_buf[tstate.cur];
30370035Sjhb
30470035Sjhb	/* Skip over unused entries. */
30572755Sjhb	if (kp->ktr_desc == NULL) {
30672755Sjhb		db_printf("--- End of trace buffer ---\n");
30772755Sjhb		return (0);
30872755Sjhb	}
30972755Sjhb	db_printf("%d: ", tstate.cur);
31070035Sjhb#ifdef SMP
31172755Sjhb	db_printf("cpu%d ", kp->ktr_cpu);
31270035Sjhb#endif
31393503Sjake	if (db_ktr_verbose) {
31493503Sjake		db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp,
31593503Sjake		    kp->ktr_file, kp->ktr_line);
31693503Sjake	}
31793503Sjake	db_printf(kp->ktr_desc, kp->ktr_parms[0], kp->ktr_parms[1],
31893503Sjake	    kp->ktr_parms[2], kp->ktr_parms[3], kp->ktr_parms[4],
31993503Sjake	    kp->ktr_parms[5]);
32072755Sjhb	db_printf("\n");
32170035Sjhb
32270035Sjhb	if (tstate.first == -1)
32370035Sjhb		tstate.first = tstate.cur;
32470035Sjhb
32570035Sjhb	if (--tstate.cur < 0)
32670035Sjhb		tstate.cur = KTR_ENTRIES - 1;
32770035Sjhb
32870035Sjhb	return (1);
32970035Sjhb}
33070035Sjhb
33170035Sjhb#endif	/* DDB */
332