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.
This commit is contained in:
mrg 2015-10-29 00:27:08 +00:00
parent 091c49eab9
commit 679d7c25a6
6 changed files with 224 additions and 39 deletions

View File

@ -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

View File

@ -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

View File

@ -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_history *hists[])
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) /* XXX only support 32 hists */
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);

View File

@ -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 1.72 2011/09/01 18:25:44 matt Exp $");
#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 sys_reboot_args *uap, register_t *retval)
#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
int scdebug = SCDEBUG_CALLS|SCDEBUG_RETURNS|SCDEBUG_SHOWARGS|SCDEBUG_ALL;
#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
#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 register_t args[])
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, const register_t retval[])
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
}

View File

@ -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_history);
#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

View File

@ -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/ddbvar.h */
#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[]);