Add explicit static DTrace tracing to the callout mechanism, capturing

pointers to the callout handler just before and just after the callout
it invoked.  I attempted to do this in a manner congruent to tracing in
Solaris's callout mechanism, but couldn't quite use the same names due
to convention and syntax differences.

Example DTrace script to generate a distribution graph of callout
execution times:

callout_execute:::callout_start
{
        self->cstart = timestamp;
}

callout_execute:::callout_end
{

        @length = quantize(timestamp - self->cstart);
}

Reviewed by:	jb
MFC after:	3 days

1 files changed, 15 insertions, 0 deletions

diff --git a/sys/kern/kern_timeout.c b/sys/kern/kern_timeout.c
index af887a0..7df03dc 100644
--- a/sys/kern/kern_timeout.c
+++ b/sys/kern/kern_timeout.c
@@ -37,6 +37,8 @@
 #include <sys/cdefs.h>
 __FBSDID("$FreeBSD$");
 
+#include "opt_kdtrace.h"
+
 #include <sys/param.h>
 #include <sys/systm.h>
 #include <sys/bus.h>
@@ -49,10 +51,19 @@ __FBSDID("$FreeBSD$");
 #include <sys/malloc.h>
 #include <sys/mutex.h>
 #include <sys/proc.h>
+#include <sys/sdt.h>
 #include <sys/sleepqueue.h>
 #include <sys/sysctl.h>
 #include <sys/smp.h>
 
+SDT_PROVIDER_DEFINE(callout_execute);
+SDT_PROBE_DEFINE(callout_execute, kernel, , callout_start);
+SDT_PROBE_ARGTYPE(callout_execute, kernel, , callout_start, 0,
+    "struct callout *");
+SDT_PROBE_DEFINE(callout_execute, kernel, , callout_end); 
+SDT_PROBE_ARGTYPE(callout_execute, kernel, , callout_end, 0,
+    "struct callout *");
+
 static int avg_depth;
 SYSCTL_INT(_debug, OID_AUTO, to_avg_depth, CTLFLAG_RD, &avg_depth, 0,
     "Average number of items examined per softclock call. Units = 1/1000");
@@ -395,7 +406,11 @@ softclock(void *arg)
 				binuptime(&bt1);
 #endif
 				THREAD_NO_SLEEPING();
+				SDT_PROBE(callout_execute, kernel, ,
+				    callout_start, c, 0, 0, 0, 0);
 				c_func(c_arg);
+				SDT_PROBE(callout_execute, kernel, ,
+				    callout_end, c, 0, 0, 0, 0);
 				THREAD_SLEEPING_OK();
 #ifdef DIAGNOSTIC
 				binuptime(&bt2);