Module Name: src
Committed By: mrg
Date: Thu Oct 29 00:27:08 UTC 2015
Modified Files:
src/share/man/man4: options.4
src/sys/kern: init_main.c kern_history.c kern_xxx.c
src/sys/sys: kernhist.h systm.h
Log Message:
introduce a new way of handling SYSCALL_DEBUG messages -- send them to
a kernel history, settable via the SCDEBUG_KERNHIST flag.
this requires a fairly significantly different set of messages than the
normal debug as histories are restricted:
- each message can take one literal format string and upto 4
arguments
- the arguments can not be strings if you want vmstat -u to
work (this could be fixed, and i might, as it would be nice
if we could print syscall names as well as numbers.)
introduce SCDEBUG_DEFAULT that is settable in the kernel config.
fix a problem in kernhist_dump_histories() where it would crash when a
history with no allocated entries was found.
extend kernhist_dumpmask() to handle the usbhist and scdebughist.
To generate a diff of this commit:
cvs rdiff -u -r1.449 -r1.450 src/share/man/man4/options.4
cvs rdiff -u -r1.471 -r1.472 src/sys/kern/init_main.c
cvs rdiff -u -r1.1 -r1.2 src/sys/kern/kern_history.c
cvs rdiff -u -r1.72 -r1.73 src/sys/kern/kern_xxx.c
cvs rdiff -u -r1.9 -r1.10 src/sys/sys/kernhist.h
cvs rdiff -u -r1.268 -r1.269 src/sys/sys/systm.h
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
Modified files:
Index: src/share/man/man4/options.4
diff -u src/share/man/man4/options.4:1.449 src/share/man/man4/options.4:1.450
--- src/share/man/man4/options.4:1.449 Thu Aug 20 11:05:06 2015
+++ src/share/man/man4/options.4 Thu Oct 29 00:27:08 2015
@@ -1,4 +1,4 @@
-.\" $NetBSD: options.4,v 1.449 2015/08/20 11:05:06 wiz Exp $
+.\" $NetBSD: options.4,v 1.450 2015/10/29 00:27:08 mrg Exp $
.\"
.\" Copyright (c) 1996
.\" Perry E. Metzger. All rights reserved.
@@ -30,7 +30,7 @@
.\" THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
.\"
.\"
-.Dd August 20, 2015
+.Dd October 28, 2015
.Dt OPTIONS 4
.Os
.Sh NAME
@@ -668,7 +668,9 @@ These logs can be displayed by using
from DDB.
See the kernel source file
.Pa sys/kern/kern_history.c
-for details.
+and the
+.Xr kernhist 9
+manual for details.
.It Cd options KERNHIST_PRINT
Prints the kernel history logs on the system console as entries are added.
Note that the output is
@@ -1508,6 +1510,36 @@ See
for details.
.Em NOTE :
not available on all architectures.
+.It Cd options SCDEBUG_DEFAULT
+Used with the
+.Cd options SYSCALL_DEBUG
+described below to choose which types of events are displayed.
+.Pp
+.Bl -tag -width "SCDEBUG_KERNHIST" -compact -offset indent
+.It Dv SCDEBUG_CALLS
+Show system call entry points.
+.It Dv SCDEBUG_RETURNS
+Show system call exit points.
+.It Dv SCDEBUG_ALL
+Show all system call requestes, including unimplemented calls.
+.It Dv SCDEBUG_SHOWARGS
+Show the arguments provided.
+.It Dv SCDEBUG_KERNHIST
+Store a restricted form of the system call debug in a kernel history
+instead of printing it to the console. This option relies upon
+.Cd options KERNHIST .
+.El
+.Pp
+The default value is
+.Dv (SCDEBUG_CALLS|SCDEBUG_RETURNS|SCDEBUG_SHOWARGS) .
+.It Cd options SYSCALL_DEBUG
+Useful for debugging system call issues, usually in early single user bringup.
+By default, writes entries to the system console for most system call events.
+Can be configured with the
+.Cd options SCDEBUG_DEFAULT
+option to to use the
+.Cd options KERNHIST
+facility instead.
.It Cd options SYSCALL_STATS
Count the number of times each system call number is called.
The values can be read through the sysctl interface and displayed using
@@ -2733,7 +2765,8 @@ bolded
.Xr quotaon 8 ,
.Xr rpc.rquotad 8 ,
.Xr sysctl 8 ,
-.Xr in_getifa 9
+.Xr in_getifa 9 ,
+.Xr kernhist 9
.Sh HISTORY
The
.Nm
Index: src/sys/kern/init_main.c
diff -u src/sys/kern/init_main.c:1.471 src/sys/kern/init_main.c:1.472
--- src/sys/kern/init_main.c:1.471 Sat Oct 17 13:52:52 2015
+++ src/sys/kern/init_main.c Thu Oct 29 00:27:08 2015
@@ -1,4 +1,4 @@
-/* $NetBSD: init_main.c,v 1.471 2015/10/17 13:52:52 jmcneill Exp $ */
+/* $NetBSD: init_main.c,v 1.472 2015/10/29 00:27:08 mrg Exp $ */
/*-
* Copyright (c) 2008, 2009 The NetBSD Foundation, Inc.
@@ -97,7 +97,7 @@
*/
#include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: init_main.c,v 1.471 2015/10/17 13:52:52 jmcneill Exp $");
+__KERNEL_RCSID(0, "$NetBSD: init_main.c,v 1.472 2015/10/29 00:27:08 mrg Exp $");
#include "opt_ddb.h"
#include "opt_ipsec.h"
@@ -601,6 +601,8 @@ main(void)
procinit_sysctl();
+ scdebug_init();
+
/*
* Create process 1 (init(8)). We do this now, as Unix has
* historically had init be process 1, and changing this would
Index: src/sys/kern/kern_history.c
diff -u src/sys/kern/kern_history.c:1.1 src/sys/kern/kern_history.c:1.2
--- src/sys/kern/kern_history.c:1.1 Tue May 17 04:18:06 2011
+++ src/sys/kern/kern_history.c Thu Oct 29 00:27:08 2015
@@ -1,4 +1,4 @@
-/* $NetBSD: kern_history.c,v 1.1 2011/05/17 04:18:06 mrg Exp $ */
+/* $NetBSD: kern_history.c,v 1.2 2015/10/29 00:27:08 mrg Exp $ */
/*
* Copyright (c) 1997 Charles D. Cranor and Washington University.
@@ -33,18 +33,30 @@
*/
#include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: kern_history.c,v 1.1 2011/05/17 04:18:06 mrg Exp $");
+__KERNEL_RCSID(0, "$NetBSD: kern_history.c,v 1.2 2015/10/29 00:27:08 mrg Exp $");
#include "opt_kernhist.h"
-#include "opt_uvmhist.h"
#include "opt_ddb.h"
+#include "opt_uvmhist.h"
+#include "opt_usb.h"
+#include "opt_syscall_debug.h"
#include <sys/param.h>
#include <sys/systm.h>
#include <sys/cpu.h>
#include <sys/kernhist.h>
+#ifdef UVMHIST
#include <uvm/uvm.h>
+#endif
+
+#ifdef USB_DEBUG
+#include <dev/usb/usbhist.h>
+#endif
+
+#ifdef SYSCALL_DEBUG
+KERNHIST_DECL(scdebughist);
+#endif
/*
* globals
@@ -112,6 +124,8 @@ kernhist_dump_histories(struct kern_hist
restart:
if (cur[lcv] == -1)
continue;
+ if (!hists[lcv]->e)
+ continue;
/*
* if the format is empty, go to the next entry
@@ -174,6 +188,16 @@ kernhist_dumpmask(u_int32_t bitmask) /*
hists[i++] = &loanhist;
#endif
+#ifdef USB_DEBUG
+ if ((bitmask & KERNHIST_USBHIST) || bitmask == 0)
+ hists[i++] = &usbhist;
+#endif
+
+#ifdef SYSCALL_DEBUG
+ if ((bitmask & KERNHIST_SCDEBUGHIST) || bitmask == 0)
+ hists[i++] = &scdebughist;
+#endif
+
hists[i] = NULL;
kernhist_dump_histories(hists);
Index: src/sys/kern/kern_xxx.c
diff -u src/sys/kern/kern_xxx.c:1.72 src/sys/kern/kern_xxx.c:1.73
--- src/sys/kern/kern_xxx.c:1.72 Thu Sep 1 18:25:44 2011
+++ src/sys/kern/kern_xxx.c Thu Oct 29 00:27:08 2015
@@ -1,4 +1,4 @@
-/* $NetBSD: kern_xxx.c,v 1.72 2011/09/01 18:25:44 matt Exp $ */
+/* $NetBSD: kern_xxx.c,v 1.73 2015/10/29 00:27:08 mrg Exp $ */
/*
* Copyright (c) 1982, 1986, 1989, 1993
@@ -32,10 +32,11 @@
*/
#include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: kern_xxx.c,v 1.72 2011/09/01 18:25:44 matt Exp $");
+__KERNEL_RCSID(0, "$NetBSD: kern_xxx.c,v 1.73 2015/10/29 00:27:08 mrg Exp $");
#ifdef _KERNEL_OPT
#include "opt_syscall_debug.h"
+#include "opt_kernhist.h"
#endif
#include <sys/param.h>
@@ -49,6 +50,7 @@ __KERNEL_RCSID(0, "$NetBSD: kern_xxx.c,v
#include <sys/syscall.h>
#include <sys/syscallargs.h>
#include <sys/kauth.h>
+#include <sys/kernhist.h>
/* ARGSUSED */
int
@@ -102,42 +104,134 @@ sys_reboot(struct lwp *l, const struct s
#ifdef SYSCALL_DEBUG
#define SCDEBUG_CALLS 0x0001 /* show calls */
#define SCDEBUG_RETURNS 0x0002 /* show returns */
-#define SCDEBUG_ALL 0x0004 /* even syscalls that are implemented */
+#define SCDEBUG_ALL 0x0004 /* even syscalls that are not implemented */
#define SCDEBUG_SHOWARGS 0x0008 /* show arguments to calls */
+#define SCDEBUG_KERNHIST 0x0010 /* use kernhist instead of printf */
-#if 0
-int scdebug = SCDEBUG_CALLS|SCDEBUG_RETURNS|SCDEBUG_SHOWARGS;
+#ifndef SCDEBUG_DEFAULT
+#define SCDEBUG_DEFAULT (SCDEBUG_CALLS|SCDEBUG_RETURNS|SCDEBUG_SHOWARGS)
+#endif
+
+int scdebug = SCDEBUG_DEFAULT;
+
+#ifdef KERNHIST
+KERNHIST_DEFINE(scdebughist);
+#define SCDEBUG_KERNHIST_FUNC(a) KERNHIST_FUNC(a)
+#define SCDEBUG_KERNHIST_CALLED(a) KERNHIST_CALLED(a)
+#define SCDEBUG_KERNHIST_LOG(a,b,c,d,e,f) KERNHIST_LOG(a,b,c,d,e,f)
+#else
+#define SCDEBUG_KERNHIST_FUNC(a) /* nothing */
+#define SCDEBUG_KERNHIST_CALLED(a) /* nothing */
+#define SCDEBUG_KERNHIST_LOG(a,b,c,d,e,f) /* nothing */
+/* The non-kernhist support version can elide all this code easily. */
+#undef SCDEBUG_KERNHIST
+#define SCDEBUG_KERNHIST 0
+#endif
+
+#ifdef __HAVE_MINIMAL_EMUL
+#define CODE_NOT_OK(code, em) ((int)(code) < 0)
#else
-int scdebug = SCDEBUG_CALLS|SCDEBUG_RETURNS|SCDEBUG_SHOWARGS|SCDEBUG_ALL;
+#define CODE_NOT_OK(code, em) (((int)(code) < 0) || \
+ ((int)(code) >= (em)->e_nsysent))
#endif
void
scdebug_call(register_t code, const register_t args[])
{
+ SCDEBUG_KERNHIST_FUNC("scdebug_call");
struct lwp *l = curlwp;
struct proc *p = l->l_proc;
const struct sysent *sy;
const struct emul *em;
int i;
- if (!(scdebug & SCDEBUG_CALLS))
+ if ((scdebug & SCDEBUG_CALLS) == 0)
return;
+ if (scdebug & SCDEBUG_KERNHIST)
+ SCDEBUG_KERNHIST_CALLED(scdebughist);
+
em = p->p_emul;
sy = &em->e_sysent[code];
- if (!(scdebug & SCDEBUG_ALL || (int)code < 0
-#ifndef __HAVE_MINIMAL_EMUL
- || code >= em->e_nsysent
-#endif
- || sy->sy_call == sys_nosys))
+
+ if ((scdebug & SCDEBUG_ALL) == 0 &&
+ (CODE_NOT_OK(code, em) || sy->sy_call == sys_nosys)) {
+ if (scdebug & SCDEBUG_KERNHIST)
+ SCDEBUG_KERNHIST_LOG(scdebughist, "", 0, 0, 0, 0);
+ return;
+ }
+
+ /*
+ * The kernhist version of scdebug needs to restrict the usage
+ * compared to the normal version. histories must avoid these
+ * sorts of usage:
+ *
+ * - the format string *must* be literal, as it is used
+ * at display time in the kernel or userland
+ * - strings in the format will cause vmstat -u to crash
+ * so avoid using %s formats
+ *
+ * to avoid these, we have a fairly long block to print args
+ * as the format needs to change for each, and we can't just
+ * call printf() on each argument until we're done.
+ */
+ if (scdebug & SCDEBUG_KERNHIST) {
+ if (CODE_NOT_OK(code, em)) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "pid %d:%d: OUT OF RANGE (%ld)",
+ p->p_pid, l->l_lid, code, 0);
+ } else {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "pid %d:%d: num %d call %p",
+ p->p_pid, l->l_lid, code, sy->sy_call);
+ if ((scdebug & SCDEBUG_SHOWARGS) == 0)
+ return;
+
+ if (sy->sy_narg > 7) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[4-7]: (%lx, %lx, %lx, %lx, ...)",
+ (long)args[4], (long)args[5],
+ (long)args[6], (long)args[7]);
+ } else if (sy->sy_narg > 6) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[4-6]: (%lx, %lx, %lx)",
+ (long)args[4], (long)args[5],
+ (long)args[6], 0);
+ } else if (sy->sy_narg > 5) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[4-5]: (%lx, %lx)",
+ (long)args[4], (long)args[5], 0, 0);
+ } else if (sy->sy_narg == 5) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[4]: (%lx)",
+ (long)args[4], 0, 0, 0);
+ }
+
+ if (sy->sy_narg > 3) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[0-3]: (%lx, %lx, %lx, %lx, ...)",
+ (long)args[0], (long)args[1],
+ (long)args[2], (long)args[3]);
+ } else if (sy->sy_narg > 2) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[0-2]: (%lx, %lx, %lx)",
+ (long)args[0], (long)args[1],
+ (long)args[2], 0);
+ } else if (sy->sy_narg > 1) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[0-1]: (%lx, %lx)",
+ (long)args[0], (long)args[1], 0, 0);
+ } else if (sy->sy_narg == 1) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "args[0]: (%lx)",
+ (long)args[0], 0, 0, 0);
+ }
+ }
return;
+ }
printf("proc %d (%s): %s num ", p->p_pid, p->p_comm, em->e_name);
- if ((int)code < 0
-#ifndef __HAVE_MINIMAL_EMUL
- || code >= em->e_nsysent
-#endif
- )
+ if (CODE_NOT_OK(code, em))
printf("OUT OF RANGE (%ld)", (long)code);
else {
printf("%ld call: %s", (long)code, em->e_syscallnames[code]);
@@ -155,29 +249,45 @@ scdebug_call(register_t code, const regi
void
scdebug_ret(register_t code, int error, const register_t retval[])
{
+ SCDEBUG_KERNHIST_FUNC("scdebug_ret");
struct lwp *l = curlwp;
struct proc *p = l->l_proc;
const struct sysent *sy;
const struct emul *em;
- if (!(scdebug & SCDEBUG_RETURNS))
+ if ((scdebug & SCDEBUG_RETURNS) == 0)
return;
+ if (scdebug & SCDEBUG_KERNHIST)
+ SCDEBUG_KERNHIST_CALLED(scdebughist);
+
em = p->p_emul;
sy = &em->e_sysent[code];
- if (!(scdebug & SCDEBUG_ALL || (int)code < 0
-#ifndef __HAVE_MINIMAL_EMUL
- || (int)code >= em->e_nsysent
-#endif
- || sy->sy_call == sys_nosys))
+ if ((scdebug & SCDEBUG_ALL) == 0 &&
+ (CODE_NOT_OK(code, em) || sy->sy_call == sys_nosys)) {
+ if (scdebug & SCDEBUG_KERNHIST)
+ SCDEBUG_KERNHIST_LOG(scdebughist, "", 0, 0, 0, 0);
+ return;
+ }
+
+ if (scdebug & SCDEBUG_KERNHIST) {
+ if (CODE_NOT_OK(code, em)) {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "pid %d:%d: OUT OF RANGE (%ld)",
+ p->p_pid, l->l_lid, code, 0);
+ } else {
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "pid %d:%d: num %ld",
+ p->p_pid, l->l_lid, code, 0);
+ SCDEBUG_KERNHIST_LOG(scdebughist,
+ "ret: err = %d, rv = 0x%lx,0x%lx",
+ error, (long)retval[0], (long)retval[1], 0);
+ }
return;
+ }
printf("proc %d (%s): %s num ", p->p_pid, p->p_comm, em->e_name);
- if ((int)code < 0
-#ifndef __HAVE_MINIMAL_EMUL
- || code >= em->e_nsysent
-#endif
- )
+ if (CODE_NOT_OK(code, em))
printf("OUT OF RANGE (%ld)", (long)code);
else
printf("%ld ret %s: err = %d, rv = 0x%lx,0x%lx", (long)code,
@@ -186,3 +296,16 @@ scdebug_ret(register_t code, int error,
printf("\n");
}
#endif /* SYSCALL_DEBUG */
+
+#ifndef SCDEBUG_KERNHIST_SIZE
+#define SCDEBUG_KERNHIST_SIZE 500
+#endif
+
+void
+scdebug_init(void)
+{
+#if defined(SYSCALL_DEBUG) && defined(KERNHIST)
+ /* Setup scdebughist kernel history */
+ KERNHIST_INIT(scdebughist, SCDEBUG_KERNHIST_SIZE);
+#endif
+}
Index: src/sys/sys/kernhist.h
diff -u src/sys/sys/kernhist.h:1.9 src/sys/sys/kernhist.h:1.10
--- src/sys/sys/kernhist.h:1.9 Sun Mar 30 15:53:37 2014
+++ src/sys/sys/kernhist.h Thu Oct 29 00:27:08 2015
@@ -1,4 +1,4 @@
-/* $NetBSD: kernhist.h,v 1.9 2014/03/30 15:53:37 matt Exp $ */
+/* $NetBSD: kernhist.h,v 1.10 2015/10/29 00:27:08 mrg Exp $ */
/*
* Copyright (c) 1997 Charles D. Cranor and Washington University.
@@ -85,6 +85,8 @@ LIST_HEAD(kern_history_head, kern_histor
#define KERNHIST_UVMPDHIST 0x00000002 /* pdhist */
#define KERNHIST_UVMUBCHIST 0x00000004 /* ubchist */
#define KERNHIST_UVMLOANHIST 0x00000008 /* loanhist */
+#define KERNHIST_USBHIST 0x00000010 /* usbhist */
+#define KERNHIST_SCDEBUGHIST 0x00000020 /* scdebughist */
#ifdef _KERNEL
Index: src/sys/sys/systm.h
diff -u src/sys/sys/systm.h:1.268 src/sys/sys/systm.h:1.269
--- src/sys/sys/systm.h:1.268 Fri Aug 28 07:18:40 2015
+++ src/sys/sys/systm.h Thu Oct 29 00:27:08 2015
@@ -1,4 +1,4 @@
-/* $NetBSD: systm.h,v 1.268 2015/08/28 07:18:40 knakahara Exp $ */
+/* $NetBSD: systm.h,v 1.269 2015/10/29 00:27:08 mrg Exp $ */
/*-
* Copyright (c) 1982, 1988, 1991, 1993
@@ -489,6 +489,7 @@ extern int db_fromconsole; /* XXX ddb/dd
#endif /* _KERNEL */
/* For SYSCALL_DEBUG */
+void scdebug_init(void);
void scdebug_call(register_t, const register_t[]);
void scdebug_ret(register_t, int, const register_t[]);
