Author: jeff
Date: Wed Dec 19 20:10:00 2012
New Revision: 244445
URL: http://svnweb.freebsd.org/changeset/base/244445
Log:
- Add new machine parsable KTR macros for timing events.
- Use this new format to automatically handle syscalls and VOPs. This
changes the earlier format but is still human readable.
Sponsored by: EMC / Isilon Storage Division
Modified:
head/sys/kern/subr_syscall.c
head/sys/sys/ktr.h
head/sys/tools/vnode_if.awk
Modified: head/sys/kern/subr_syscall.c
==============================================================================
--- head/sys/kern/subr_syscall.c Wed Dec 19 20:08:06 2012
(r244444)
+++ head/sys/kern/subr_syscall.c Wed Dec 19 20:10:00 2012
(r244445)
@@ -77,13 +77,12 @@ syscallenter(struct thread *td, struct s
if (KTRPOINT(td, KTR_SYSCALL))
ktrsyscall(sa->code, sa->narg, sa->args);
#endif
-
- CTR6(KTR_SYSC,
-"syscall: td=%p pid %d %s (%#lx, %#lx, %#lx)",
- td, td->td_proc->p_pid, syscallname(p, sa->code),
- sa->args[0], sa->args[1], sa->args[2]);
+ KTR_START4(KTR_SYSC, "syscall", syscallname(p, sa->code),
+ td, "pid:%d", td->td_proc->p_pid, "arg0:%p", sa->args[0],
+ "arg1:%p", sa->args[1], "arg2:%p", sa->args[2]);
if (error == 0) {
+
STOPEVENT(p, S_SCE, sa->narg);
if (p->p_flag & P_TRACED && p->p_stops & S_PT_SCE) {
PROC_LOCK(p);
@@ -150,10 +149,12 @@ syscallenter(struct thread *td, struct s
sa->callp, NULL, (error) ? -1 : td->td_retval[0]);
#endif
syscall_thread_exit(td, sa->callp);
- CTR4(KTR_SYSC, "syscall: p=%p error=%d return %#lx %#lx",
- p, error, td->td_retval[0], td->td_retval[1]);
}
retval:
+ KTR_STOP4(KTR_SYSC, "syscall", syscallname(p, sa->code),
+ td, "pid:%d", td->td_proc->p_pid, "error:%d", error,
+ "retval0:%#lx", td->td_retval[0], "retval1:%#lx",
+ td->td_retval[1]);
if (traced) {
PROC_LOCK(p);
td->td_dbgflags &= ~TDB_SCE;
@@ -176,9 +177,6 @@ syscallret(struct thread *td, int error,
*/
userret(td, td->td_frame);
- CTR4(KTR_SYSC, "syscall %s exit thread %p pid %d proc %s",
- syscallname(p, sa->code), td, td->td_proc->p_pid, td->td_name);
-
#ifdef KTRACE
if (KTRPOINT(td, KTR_SYSRET)) {
ktrsysret(sa->code, (td->td_pflags & TDP_NERRNO) == 0 ?
Modified: head/sys/sys/ktr.h
==============================================================================
--- head/sys/sys/ktr.h Wed Dec 19 20:08:06 2012 (r244444)
+++ head/sys/sys/ktr.h Wed Dec 19 20:10:00 2012 (r244445)
@@ -244,6 +244,50 @@ void ktr_tracepoint(u_int mask, const ch
point, a0, (v0), a1, (v1), a2, (v2), a3, (v3))
/*
+ * Start functions denote the start of a region of code or operation
+ * and should be paired with stop functions for timing of nested
+ * sequences.
+ *
+ * Specifying extra attributes with the name "key" will result in
+ * multi-part keys. For example a block device and offset pair
+ * might be used to describe a buf undergoing I/O.
+ */
+#define KTR_START0(m, egroup, ident, key)
\
+ KTR_EVENT0(m, egroup, ident, "start:0x%jX", (uintmax_t)key)
+#define KTR_START1(m, egroup, ident, key, a0, v0)
\
+ KTR_EVENT1(m, egroup, ident, "start:0x%jX", (uintmax_t)key, a0, (v0))
+#define KTR_START2(m, egroup, ident, key, a0, v0, a1, v1)
\
+ KTR_EVENT2(m, egroup, ident, "start:0x%jX", (uintmax_t)key, \
+ a0, (v0), a1, (v1))
+#define KTR_START3(m, egroup, ident, key, a0, v0, a1, v1, a2, v2)\
+ KTR_EVENT3(m, egroup, ident, "start:0x%jX", (uintmax_t)key, \
+ a0, (v0), a1, (v1), a2, (v2))
+#define KTR_START4(m, egroup, ident, key,
\
+ a0, v0, a1, v1, a2, v2, a3, v3) \
+ KTR_EVENT4(m, egroup, ident, "start:0x%jX", (uintmax_t)key, \
+ a0, (v0), a1, (v1), a2, (v2), a3, (v3))
+
+/*
+ * Stop functions denote the end of a region of code or operation
+ * and should be paired with start functions for timing of nested
+ * sequences.
+ */
+#define KTR_STOP0(m, egroup, ident, key)
\
+ KTR_EVENT0(m, egroup, ident, "stop:0x%jX", (uintmax_t)key)
+#define KTR_STOP1(m, egroup, ident, key, a0, v0)
\
+ KTR_EVENT1(m, egroup, ident, "stop:0x%jX", (uintmax_t)key, a0, (v0))
+#define KTR_STOP2(m, egroup, ident, key, a0, v0, a1, v1)
\
+ KTR_EVENT2(m, egroup, ident, "stop:0x%jX", (uintmax_t)key, \
+ a0, (v0), a1, (v1))
+#define KTR_STOP3(m, egroup, ident, key, a0, v0, a1, v1, a2, v2)\
+ KTR_EVENT3(m, egroup, ident, "stop:0x%jX", (uintmax_t)key, \
+ a0, (v0), a1, (v1), a2, (v2))
+#define KTR_STOP4(m, egroup, ident,
\
+ key, a0, v0, a1, v1, a2, v2, a3, v3) \
+ KTR_EVENT4(m, egroup, ident, "stop:0x%jX", (uintmax_t)key, \
+ a0, (v0), a1, (v1), a2, (v2), a3, (v3))
+
+/*
* Trace initialization events, similar to CTR with KTR_INIT, but
* completely ifdef'ed out if KTR_INIT isn't in KTR_COMPILE (to
* save string space, the compiler doesn't optimize out strings
Modified: head/sys/tools/vnode_if.awk
==============================================================================
--- head/sys/tools/vnode_if.awk Wed Dec 19 20:08:06 2012 (r244444)
+++ head/sys/tools/vnode_if.awk Wed Dec 19 20:10:00 2012 (r244445)
@@ -222,8 +222,6 @@ while ((getline < srcfile) > 0) {
name = $1;
uname = toupper(name);
- # Start constructing a ktrpoint string
- ctrstr = "\"" uname;
# Get the function arguments.
for (numargs = 0; ; ++numargs) {
if ((getline < srcfile) <= 0) {
@@ -267,27 +265,15 @@ while ((getline < srcfile) > 0) {
# remove trailing space (if any)
sub(/ $/, "");
types[numargs] = $0;
-
- # We can do a maximum of 6 arguments to CTR*
- if (numargs <= 6) {
- if (numargs == 0)
- ctrstr = ctrstr "(" args[numargs];
- else
- ctrstr = ctrstr ", " args[numargs];
- if (types[numargs] ~ /\*/)
- ctrstr = ctrstr " 0x%lX";
- else
- ctrstr = ctrstr " %ld";
- }
}
- if (numargs > 6)
- ctrargs = 6;
+ if (numargs > 4)
+ ctrargs = 4;
else
ctrargs = numargs;
- ctrstr = "\tCTR" ctrargs "(KTR_VOP,\n\t " ctrstr ")\",\n\t ";
- ctrstr = ctrstr "a->a_" args[0];
+ ctrstr = ctrargs "(KTR_VOP, \"VOP\", \"" uname "\", a,\n\t ";
+ ctrstr = ctrstr "\"" args[0] ":0x%jX\", (uintptr_t)a->a_" args[0];
for (i = 1; i < ctrargs; ++i)
- ctrstr = ctrstr ", a->a_" args[i];
+ ctrstr = ctrstr ", \"" args[i] ":0x%jX\", a->a_" args[i];
ctrstr = ctrstr ");";
if (pfile) {
@@ -377,12 +363,12 @@ while ((getline < srcfile) > 0) {
printc("\tSDT_PROBE(vfs, vop, " name ", entry, a->a_" args[0]
", a, 0, 0, 0);\n");
for (i = 0; i < numargs; ++i)
add_debug_code(name, args[i], "Entry", "\t");
+ printc("\tKTR_START" ctrstr);
add_pre(name);
printc("\tif (vop->"name" != NULL)")
printc("\t\trc = vop->"name"(a);")
printc("\telse")
printc("\t\trc = vop->vop_bypass(&a->a_gen);")
- printc(ctrstr);
printc("\tSDT_PROBE(vfs, vop, " name ", return, a->a_" args[0]
", a, rc, 0, 0);\n");
printc("\tif (rc == 0) {");
for (i = 0; i < numargs; ++i)
@@ -392,6 +378,7 @@ while ((getline < srcfile) > 0) {
add_debug_code(name, args[i], "Error", "\t\t");
printc("\t}");
add_post(name);
+ printc("\tKTR_STOP" ctrstr);
printc("\treturn (rc);");
printc("}\n");
_______________________________________________
svn-src-all@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-all
To unsubscribe, send any mail to "svn-src-all-unsubscr...@freebsd.org"
