Giant and timeouts and more timeouts, and more timeouts... and NFS.

[Robert Watson]

For those interested, here's the patch I'm using for callout/timeout
sampling.  While it's not exactly perfect, it has quite a bit of utility.

To use it, do the following:

(1) Compile and boot a kernel with this patch applied to kern_timeout.c

(2) Set up the sample set requirements for whatever test you want to run
    by setting some combination of debug.to_cfunc_mpsafe and
    debug.to_cfunc_notmpsafe to 0 and 1.

(3) Reset the sample buffer using debug.to_cfunc_reset=1.

(4) Perform the test

(5) Turn off the sampling using debug.to_cfunc_mpsafe and
    debug.to_cfunc_notmpsafe.

(6) Dump the debug.to_cfunc sysctl to a file or the like.

Note that debug.to_cfunc generates a very long string, so sysctl -a > foo
gets longer as sampling goes on.

You can then convert the function pointers back into symbols using your
favorite copy of the same kernel you booted using nm or the like.

Robert N M Watson             FreeBSD Core Team, TrustedBSD Projects
robert at fledge.watson.org      Senior Research Scientist, McAfee Research

--- //depot/projects/netperf_socket/sys/kern/kern_timeout.c	2004/01/18 09:46:57
+++ //depot/user/rwatson/netperf/sys/kern/kern_timeout.c	2004/03/08 08:37:54
@@ -47,6 +47,7 @@
 #include <sys/kernel.h>
 #include <sys/lock.h>
 #include <sys/mutex.h>
+#include <sys/sbuf.h>
 #include <sys/sysctl.h>
 
 static int avg_depth;
@@ -58,6 +59,89 @@
 static int avg_mpcalls;
 SYSCTL_INT(_debug, OID_AUTO, to_avg_mpcalls, CTLFLAG_RD, &avg_mpcalls, 0,
     "Average number of MP callouts made per softclock call. Units = 1/1000");
+
+/*-
+ * Sampling buffer of function pointers executed by timeouts and callouts.
+ * This circular buffer wraps when it fills, and uses an inefficient
+ * sbuf-based sysctl to dump sample data to userspace.  Sysctls can select
+ * to monitor mpsafe and !mpsafe callouts/timeouts as desired.  Suggested
+ * use is: (1) set sample of interest (mpsafe/notmpsafe), (2) reset the
+ * buffer, (3) do some benchmark/test, (5) disable sampling, (6) dump
+ * buffer.
+ *
+ * XXX: ifdef TIMEOUT_SAMPLING?
+ */
+
+#define	MAXFUNC	200000
+static void * func_array[MAXFUNC];
+static int array_off;
+
+static void
+push_cfunc(void *ptr)
+{
+
+	/* XXX */
+	func_array[array_off % MAXFUNC] = ptr;
+	array_off++;
+}
+
+static int
+sysctl_cfunc(SYSCTL_HANDLER_ARGS)
+{
+	struct sbuf sb;
+	int error, i;
+
+	if (req->newptr != NULL)
+		return (EINVAL);
+
+	sbuf_new(&sb, NULL, 0, SBUF_AUTOEXTEND);
+
+	for (i = 0; i < MAXFUNC; i++) {
+		if (func_array[i] == NULL)
+			break;
+		sbuf_printf(&sb, "%p ", func_array[i]);
+	}
+	sbuf_finish(&sb);
+
+	error = sysctl_handle_string(oidp, sbuf_data(&sb), sbuf_len(&sb) + 1, req);
+
+	sbuf_delete(&sb);
+
+	return (error);
+}
+
+SYSCTL_PROC(_debug, OID_AUTO, to_cfunc, CTLTYPE_STRING|CTLFLAG_RD, 0, 0,
+    sysctl_cfunc, "A", "callout/timeout sample");
+
+static int
+sysctl_cfunc_reset(SYSCTL_HANDLER_ARGS)
+{
+	int dummy, error;
+
+	dummy = 0;
+	error = sysctl_handle_int(oidp, &dummy, 0, req);
+	if (error)
+		return (error);
+
+	if (dummy != 0) {
+		bzero(func_array, sizeof(void *) * MAXFUNC);
+		array_off = 0;
+	}
+
+	return (0);
+}
+
+SYSCTL_PROC(_debug, OID_AUTO, to_cfunc_reset, CTLTYPE_INT|CTLFLAG_RW, 0, 0,
+    sysctl_cfunc_reset, "I", "Reset sample");
+
+static int cfunc_sample_mpsafe;
+static int cfunc_sample_notmpsafe;
+
+SYSCTL_INT(_debug, OID_AUTO, to_cfunc_mpsafe, CTLFLAG_RW,
+    &cfunc_sample_mpsafe, 0, "Sample mpsafe callouts");
+SYSCTL_INT(_debug, OID_AUTO, to_cfunc_notmpsafe, CTLFLAG_RW,
+    &cfunc_sample_notmpsafe, 0, "Sample !mpsafe callouts");
+
 /*
  * TODO:
  *	allocate more timeout table slots when table overflows.
@@ -216,8 +300,12 @@
 				if (!(c_flags & CALLOUT_MPSAFE)) {
 					mtx_lock(&Giant);
 					gcalls++;
+					if (cfunc_sample_mpsafe)
+						push_cfunc(c_func);
 				} else {
 					mpcalls++;
+					if (cfunc_sample_notmpsafe)
+						push_cfunc(c_func);
 				}
 #ifdef DIAGNOSTIC
 				binuptime(&bt1);