[PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem

[PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem

[Steve Dickson]

From: Trond Myklebust <Trond.Myklebust@netapp.com>

Add declarations to allow tracing of RPC call creation, running,
sleeping, and destruction.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
Signed-off-by: Steve Dickson <steved@redhat.com>
---
 include/linux/sunrpc/sched.h  |    2 +-
 include/trace/events/sunrpc.h |  124 +++++++++++++++++++++++++++++++++++++++++
 net/sunrpc/sched.c            |   12 ++++
 3 files changed, 137 insertions(+), 1 deletions(-)
 create mode 100644 include/trace/events/sunrpc.h

diff --git a/include/linux/sunrpc/sched.h b/include/linux/sunrpc/sched.h
index fe2d8e6..855cb43 100644
--- a/include/linux/sunrpc/sched.h
+++ b/include/linux/sunrpc/sched.h
@@ -263,7 +263,7 @@ static inline int rpc_task_has_priority(struct rpc_task *task, unsigned char pri
 }
 
 #ifdef RPC_DEBUG
-static inline const char * rpc_qname(struct rpc_wait_queue *q)
+static inline const char * rpc_qname(const struct rpc_wait_queue *q)
 {
 	return ((q && q->name) ? q->name : "unknown");
 }
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
new file mode 100644
index 0000000..2f82de9
--- /dev/null
+++ b/include/trace/events/sunrpc.h
@@ -0,0 +1,124 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM sunrpc
+
+#if !defined(_TRACE_SUNRPC_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_SUNRPC_H
+
+#include <linux/sunrpc/sched.h>
+#include <linux/sunrpc/clnt.h>
+#include <linux/tracepoint.h>
+
+DECLARE_EVENT_CLASS(rpc_task_running,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action),
+
+	TP_STRUCT__entry(
+		__field(const struct rpc_clnt *, clnt)
+		__field(const struct rpc_task *, task)
+		__field(const void *, action)
+		__field(unsigned long, runstate)
+		__field(int, status)
+		__field(unsigned short, flags)
+		),
+
+	TP_fast_assign(
+		__entry->clnt = clnt;
+		__entry->task = task;
+		__entry->action = action;
+		__entry->runstate = task->tk_runstate;
+		__entry->status = task->tk_status;
+		__entry->flags = task->tk_flags;
+		),
+
+	TP_printk("task:%p@%p flags=%4.4x state=%4.4lx status=%d action=%pf",
+		__entry->task,
+		__entry->clnt,
+		__entry->flags,
+		__entry->runstate,
+		__entry->status,
+		__entry->action
+		)
+);
+
+DEFINE_EVENT(rpc_task_running, rpc_task_begin,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action)
+
+);
+
+DEFINE_EVENT(rpc_task_running, rpc_task_run_action,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action)
+
+);
+
+DEFINE_EVENT(rpc_task_running, rpc_task_complete,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action)
+
+);
+
+DECLARE_EVENT_CLASS(rpc_task_queued,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const struct rpc_wait_queue *q),
+
+	TP_ARGS(clnt, task, q),
+
+	TP_STRUCT__entry(
+		__field(const struct rpc_clnt *, clnt)
+		__field(const struct rpc_task *, task)
+		__string(    qname, rpc_qname(q))
+		__field(unsigned long, timeout)
+		__field(unsigned long, runstate)
+		__field(int, status)
+		__field(unsigned short, flags)
+		),
+
+	TP_fast_assign(
+		__entry->clnt = clnt;
+		__entry->task = task;
+		__assign_str(qname, rpc_qname(q));
+		__entry->timeout = task->tk_timeout;
+		__entry->runstate = task->tk_runstate;
+		__entry->status = task->tk_status;
+		__entry->flags = task->tk_flags;
+		),
+
+	TP_printk("task:%p@%p flags=%4.4x state=%4.4lx status=%d timeout=%lu queue=%s",
+		__entry->task,
+		__entry->clnt,
+		__entry->flags,
+		__entry->runstate,
+		__entry->status,
+		__entry->timeout,
+		__get_str(qname)
+		)
+);
+
+DEFINE_EVENT(rpc_task_queued, rpc_task_sleep,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const struct rpc_wait_queue *q),
+
+	TP_ARGS(clnt, task, q)
+
+);
+
+DEFINE_EVENT(rpc_task_queued, rpc_task_wakeup,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const struct rpc_wait_queue *q),
+
+	TP_ARGS(clnt, task, q)
+
+);
+
+#endif /* _TRACE_SUNRPC_H */
+
+#include <trace/define_trace.h>
diff --git a/net/sunrpc/sched.c b/net/sunrpc/sched.c
index ec94a55..d77c41a 100644
--- a/net/sunrpc/sched.c
+++ b/net/sunrpc/sched.c
@@ -27,6 +27,9 @@
 #define RPCDBG_FACILITY		RPCDBG_SCHED
 #endif
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/sunrpc.h>
+
 /*
  * RPC slabs and memory pools
  */
@@ -246,6 +249,8 @@ static inline void rpc_task_set_debuginfo(struct rpc_task *task)
 
 static void rpc_set_active(struct rpc_task *task)
 {
+	trace_rpc_task_begin(task->tk_client, task, NULL);
+
 	rpc_task_set_debuginfo(task);
 	set_bit(RPC_TASK_ACTIVE, &task->tk_runstate);
 }
@@ -262,6 +267,8 @@ static int rpc_complete_task(struct rpc_task *task)
 	unsigned long flags;
 	int ret;
 
+	trace_rpc_task_complete(task->tk_client, task, NULL);
+
 	spin_lock_irqsave(&wq->lock, flags);
 	clear_bit(RPC_TASK_ACTIVE, &task->tk_runstate);
 	ret = atomic_dec_and_test(&task->tk_count);
@@ -317,6 +324,8 @@ static void __rpc_sleep_on(struct rpc_wait_queue *q, struct rpc_task *task,
 	dprintk("RPC: %5u sleep_on(queue \"%s\" time %lu)\n",
 			task->tk_pid, rpc_qname(q), jiffies);
 
+	trace_rpc_task_sleep(task->tk_client, task, q);
+
 	__rpc_add_wait_queue(q, task);
 
 	BUG_ON(task->tk_callback != NULL);
@@ -357,6 +366,8 @@ static void __rpc_do_wake_up_task(struct rpc_wait_queue *queue, struct rpc_task
 		return;
 	}
 
+	trace_rpc_task_wakeup(task->tk_client, task, queue);
+
 	__rpc_remove_wait_queue(queue, task);
 
 	rpc_make_runnable(task);
@@ -634,6 +645,7 @@ static void __rpc_execute(struct rpc_task *task)
 			if (do_action == NULL)
 				break;
 		}
+		trace_rpc_task_run_action(task->tk_client, task, task->tk_action);
 		do_action(task);
 
 		/*
-- 
1.7.1

[PATCH v3 0/2] SUNRPC: Added Tracing Points

[Steve Dickson]

[Resent with correct email addresses]

This series combines the trace points that Trond
posted, than now handle strings properly and the
trace points I posted, in which I integrated the 
review comments.

All these trace point were tested/enable through the
debugfs interface and being called from systemtab 
probs.

Steve Dickson (1):
  SUNRPC: Adding status trace points

Trond Myklebust (1):
  SUNRPC: Add trace events to the sunrpc subsystem

 include/linux/sunrpc/sched.h  |    2 +-
 include/trace/events/sunrpc.h |  177 +++++++++++++++++++++++++++++++++++++++++
 net/sunrpc/clnt.c             |    6 +-
 net/sunrpc/sched.c            |   12 +++
 4 files changed, 195 insertions(+), 2 deletions(-)
 create mode 100644 include/trace/events/sunrpc.h

-- 
1.7.7.5

[PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem

[Steve Dickson]

From: Trond Myklebust <Trond.Myklebust@netapp.com>

Add declarations to allow tracing of RPC call creation, running,
sleeping, and destruction.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
Signed-off-by: Steve Dickson <steved@redhat.com>
---
 include/linux/sunrpc/sched.h  |    2 +-
 include/trace/events/sunrpc.h |  124 +++++++++++++++++++++++++++++++++++++++++
 net/sunrpc/sched.c            |   12 ++++
 3 files changed, 137 insertions(+), 1 deletions(-)
 create mode 100644 include/trace/events/sunrpc.h

diff --git a/include/linux/sunrpc/sched.h b/include/linux/sunrpc/sched.h
index e775689..c600035 100644
--- a/include/linux/sunrpc/sched.h
+++ b/include/linux/sunrpc/sched.h
@@ -267,7 +267,7 @@ static inline int rpc_task_has_priority(struct rpc_task *task, unsigned char pri
 }
 
 #ifdef RPC_DEBUG
-static inline const char * rpc_qname(struct rpc_wait_queue *q)
+static inline const char * rpc_qname(const struct rpc_wait_queue *q)
 {
 	return ((q && q->name) ? q->name : "unknown");
 }
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
new file mode 100644
index 0000000..2f82de9
--- /dev/null
+++ b/include/trace/events/sunrpc.h
@@ -0,0 +1,124 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM sunrpc
+
+#if !defined(_TRACE_SUNRPC_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_SUNRPC_H
+
+#include <linux/sunrpc/sched.h>
+#include <linux/sunrpc/clnt.h>
+#include <linux/tracepoint.h>
+
+DECLARE_EVENT_CLASS(rpc_task_running,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action),
+
+	TP_STRUCT__entry(
+		__field(const struct rpc_clnt *, clnt)
+		__field(const struct rpc_task *, task)
+		__field(const void *, action)
+		__field(unsigned long, runstate)
+		__field(int, status)
+		__field(unsigned short, flags)
+		),
+
+	TP_fast_assign(
+		__entry->clnt = clnt;
+		__entry->task = task;
+		__entry->action = action;
+		__entry->runstate = task->tk_runstate;
+		__entry->status = task->tk_status;
+		__entry->flags = task->tk_flags;
+		),
+
+	TP_printk("task:%p@%p flags=%4.4x state=%4.4lx status=%d action=%pf",
+		__entry->task,
+		__entry->clnt,
+		__entry->flags,
+		__entry->runstate,
+		__entry->status,
+		__entry->action
+		)
+);
+
+DEFINE_EVENT(rpc_task_running, rpc_task_begin,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action)
+
+);
+
+DEFINE_EVENT(rpc_task_running, rpc_task_run_action,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action)
+
+);
+
+DEFINE_EVENT(rpc_task_running, rpc_task_complete,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
+
+	TP_ARGS(clnt, task, action)
+
+);
+
+DECLARE_EVENT_CLASS(rpc_task_queued,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const struct rpc_wait_queue *q),
+
+	TP_ARGS(clnt, task, q),
+
+	TP_STRUCT__entry(
+		__field(const struct rpc_clnt *, clnt)
+		__field(const struct rpc_task *, task)
+		__string(    qname, rpc_qname(q))
+		__field(unsigned long, timeout)
+		__field(unsigned long, runstate)
+		__field(int, status)
+		__field(unsigned short, flags)
+		),
+
+	TP_fast_assign(
+		__entry->clnt = clnt;
+		__entry->task = task;
+		__assign_str(qname, rpc_qname(q));
+		__entry->timeout = task->tk_timeout;
+		__entry->runstate = task->tk_runstate;
+		__entry->status = task->tk_status;
+		__entry->flags = task->tk_flags;
+		),
+
+	TP_printk("task:%p@%p flags=%4.4x state=%4.4lx status=%d timeout=%lu queue=%s",
+		__entry->task,
+		__entry->clnt,
+		__entry->flags,
+		__entry->runstate,
+		__entry->status,
+		__entry->timeout,
+		__get_str(qname)
+		)
+);
+
+DEFINE_EVENT(rpc_task_queued, rpc_task_sleep,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const struct rpc_wait_queue *q),
+
+	TP_ARGS(clnt, task, q)
+
+);
+
+DEFINE_EVENT(rpc_task_queued, rpc_task_wakeup,
+
+	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const struct rpc_wait_queue *q),
+
+	TP_ARGS(clnt, task, q)
+
+);
+
+#endif /* _TRACE_SUNRPC_H */
+
+#include <trace/define_trace.h>
diff --git a/net/sunrpc/sched.c b/net/sunrpc/sched.c
index 3341d89..2ba5739 100644
--- a/net/sunrpc/sched.c
+++ b/net/sunrpc/sched.c
@@ -28,6 +28,9 @@
 #define RPCDBG_FACILITY		RPCDBG_SCHED
 #endif
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/sunrpc.h>
+
 /*
  * RPC slabs and memory pools
  */
@@ -251,6 +254,8 @@ static inline void rpc_task_set_debuginfo(struct rpc_task *task)
 
 static void rpc_set_active(struct rpc_task *task)
 {
+	trace_rpc_task_begin(task->tk_client, task, NULL);
+
 	rpc_task_set_debuginfo(task);
 	set_bit(RPC_TASK_ACTIVE, &task->tk_runstate);
 }
@@ -267,6 +272,8 @@ static int rpc_complete_task(struct rpc_task *task)
 	unsigned long flags;
 	int ret;
 
+	trace_rpc_task_complete(task->tk_client, task, NULL);
+
 	spin_lock_irqsave(&wq->lock, flags);
 	clear_bit(RPC_TASK_ACTIVE, &task->tk_runstate);
 	ret = atomic_dec_and_test(&task->tk_count);
@@ -324,6 +331,8 @@ static void __rpc_sleep_on_priority(struct rpc_wait_queue *q,
 	dprintk("RPC: %5u sleep_on(queue \"%s\" time %lu)\n",
 			task->tk_pid, rpc_qname(q), jiffies);
 
+	trace_rpc_task_sleep(task->tk_client, task, q);
+
 	__rpc_add_wait_queue(q, task, queue_priority);
 
 	BUG_ON(task->tk_callback != NULL);
@@ -378,6 +387,8 @@ static void __rpc_do_wake_up_task(struct rpc_wait_queue *queue, struct rpc_task
 		return;
 	}
 
+	trace_rpc_task_wakeup(task->tk_client, task, queue);
+
 	__rpc_remove_wait_queue(queue, task);
 
 	rpc_make_runnable(task);
@@ -677,6 +688,7 @@ static void __rpc_execute(struct rpc_task *task)
 			if (do_action == NULL)
 				break;
 		}
+		trace_rpc_task_run_action(task->tk_client, task, task->tk_action);
 		do_action(task);
 
 		/*
-- 
1.7.7.5

[PATCH v3 2/2] SUNRPC: Adding status trace points

[Steve Dickson]

This patch adds three trace points to the status routines
in the sunrpc state machine.

The goal of these trace points is to give an Admin
the ability to check on binding status or connection
status to see if there is a potential problem.

Signed-off-by: Steve Dickson <steved@redhat.com>
---
 include/trace/events/sunrpc.h |   53 +++++++++++++++++++++++++++++++++++++++++
 net/sunrpc/clnt.c             |    6 ++++-
 2 files changed, 58 insertions(+), 1 deletions(-)

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 2f82de9..abcf45d 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -8,6 +8,59 @@
 #include <linux/sunrpc/clnt.h>
 #include <linux/tracepoint.h>
 
+DECLARE_EVENT_CLASS(rpc_task_status,
+
+	TP_PROTO(struct rpc_task *task),
+
+	TP_ARGS(task),
+
+	TP_STRUCT__entry(
+		__field(const struct rpc_task *, task)
+		__field(const struct rpc_clnt *, clnt)
+		__field(int, status)
+	),
+
+	TP_fast_assign(
+		__entry->task = task;
+		__entry->clnt = task->tk_client;
+		__entry->status = task->tk_status;
+	),
+
+	TP_printk("task:%p@%p, status %d",__entry->task, __entry->clnt, __entry->status)
+);
+
+DEFINE_EVENT(rpc_task_status, rpc_call_status,
+	TP_PROTO(struct rpc_task *task), 
+
+	TP_ARGS(task)
+);
+
+DEFINE_EVENT(rpc_task_status, rpc_bind_status,
+	TP_PROTO(struct rpc_task *task), 
+
+	TP_ARGS(task)
+);
+
+TRACE_EVENT(rpc_connect_status,
+	TP_PROTO(struct rpc_task *task, int status),
+
+	TP_ARGS(task, status),
+
+	TP_STRUCT__entry(
+		__field(const struct rpc_task *, task)
+		__field(const struct rpc_clnt *, clnt)
+		__field(int, status)
+	),
+
+	TP_fast_assign(
+		__entry->task = task;
+		__entry->clnt = task->tk_client;
+		__entry->status = status;
+	),
+
+	TP_printk("task:%p@%p, status %d",__entry->task, __entry->clnt, __entry->status)
+);
+
 DECLARE_EVENT_CLASS(rpc_task_running,
 
 	TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),
diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index f0268ea..130809a 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -36,6 +36,8 @@
 #include <linux/sunrpc/rpc_pipe_fs.h>
 #include <linux/sunrpc/metrics.h>
 #include <linux/sunrpc/bc_xprt.h>
+#include <trace/events/sunrpc.h>
+
 
 #include "sunrpc.h"
 
@@ -55,7 +57,6 @@ static DEFINE_SPINLOCK(rpc_client_lock);
 
 static DECLARE_WAIT_QUEUE_HEAD(destroy_wait);
 
-
 static void	call_start(struct rpc_task *task);
 static void	call_reserve(struct rpc_task *task);
 static void	call_reserveresult(struct rpc_task *task);
@@ -1163,6 +1164,7 @@ call_bind_status(struct rpc_task *task)
 		return;
 	}
 
+	trace_rpc_bind_status(task);
 	switch (task->tk_status) {
 	case -ENOMEM:
 		dprintk("RPC: %5u rpcbind out of memory\n", task->tk_pid);
@@ -1262,6 +1264,7 @@ call_connect_status(struct rpc_task *task)
 		return;
 	}
 
+	trace_rpc_connect_status(task, status);
 	switch (status) {
 		/* if soft mounted, test if we've timed out */
 	case -ETIMEDOUT:
@@ -1450,6 +1453,7 @@ call_status(struct rpc_task *task)
 		return;
 	}
 
+	trace_rpc_call_status(task);
 	task->tk_status = 0;
 	switch(status) {
 	case -EHOSTDOWN:
-- 
1.7.7.5

Re: [PATCH v3 2/2] SUNRPC: Adding status trace points

[Myklebust, Trond]

T24gTW9uLCAyMDEyLTAyLTA2IGF0IDEwOjA4IC0wNTAwLCBTdGV2ZSBEaWNrc29uIHdyb3RlOg0K
PiBUaGlzIHBhdGNoIGFkZHMgdGhyZWUgdHJhY2UgcG9pbnRzIHRvIHRoZSBzdGF0dXMgcm91dGlu
ZXMNCj4gaW4gdGhlIHN1bnJwYyBzdGF0ZSBtYWNoaW5lLg0KPiANCj4gVGhlIGdvYWwgb2YgdGhl
c2UgdHJhY2UgcG9pbnRzIGlzIHRvIGdpdmUgYW4gQWRtaW4NCj4gdGhlIGFiaWxpdHkgdG8gY2hl
Y2sgb24gYmluZGluZyBzdGF0dXMgb3IgY29ubmVjdGlvbg0KPiBzdGF0dXMgdG8gc2VlIGlmIHRo
ZXJlIGlzIGEgcG90ZW50aWFsIHByb2JsZW0uDQo+IA0KPiBTaWduZWQtb2ZmLWJ5OiBTdGV2ZSBE
aWNrc29uIDxzdGV2ZWRAcmVkaGF0LmNvbT4NCj4gLS0tDQo+ICBpbmNsdWRlL3RyYWNlL2V2ZW50
cy9zdW5ycGMuaCB8ICAgNTMgKysrKysrKysrKysrKysrKysrKysrKysrKysrKysrKysrKysrKysr
KysNCj4gIG5ldC9zdW5ycGMvY2xudC5jICAgICAgICAgICAgIHwgICAgNiArKysrLQ0KPiAgMiBm
aWxlcyBjaGFuZ2VkLCA1OCBpbnNlcnRpb25zKCspLCAxIGRlbGV0aW9ucygtKQ0KPiANCj4gZGlm
ZiAtLWdpdCBhL2luY2x1ZGUvdHJhY2UvZXZlbnRzL3N1bnJwYy5oIGIvaW5jbHVkZS90cmFjZS9l
dmVudHMvc3VucnBjLmgNCj4gaW5kZXggMmY4MmRlOS4uYWJjZjQ1ZCAxMDA2NDQNCj4gLS0tIGEv
aW5jbHVkZS90cmFjZS9ldmVudHMvc3VucnBjLmgNCj4gKysrIGIvaW5jbHVkZS90cmFjZS9ldmVu
dHMvc3VucnBjLmgNCj4gQEAgLTgsNiArOCw1OSBAQA0KPiAgI2luY2x1ZGUgPGxpbnV4L3N1bnJw
Yy9jbG50Lmg+DQo+ICAjaW5jbHVkZSA8bGludXgvdHJhY2Vwb2ludC5oPg0KPiAgDQo+ICtERUNM
QVJFX0VWRU5UX0NMQVNTKHJwY190YXNrX3N0YXR1cywNCj4gKw0KPiArCVRQX1BST1RPKHN0cnVj
dCBycGNfdGFzayAqdGFzayksDQo+ICsNCj4gKwlUUF9BUkdTKHRhc2spLA0KPiArDQo+ICsJVFBf
U1RSVUNUX19lbnRyeSgNCj4gKwkJX19maWVsZChjb25zdCBzdHJ1Y3QgcnBjX3Rhc2sgKiwgdGFz
aykNCj4gKwkJX19maWVsZChjb25zdCBzdHJ1Y3QgcnBjX2NsbnQgKiwgY2xudCkNCj4gKwkJX19m
aWVsZChpbnQsIHN0YXR1cykNCj4gKwkpLA0KPiArDQo+ICsJVFBfZmFzdF9hc3NpZ24oDQo+ICsJ
CV9fZW50cnktPnRhc2sgPSB0YXNrOw0KPiArCQlfX2VudHJ5LT5jbG50ID0gdGFzay0+dGtfY2xp
ZW50Ow0KPiArCQlfX2VudHJ5LT5zdGF0dXMgPSB0YXNrLT50a19zdGF0dXM7DQo+ICsJKSwNCj4g
Kw0KPiArCVRQX3ByaW50aygidGFzazolcEAlcCwgc3RhdHVzICVkIixfX2VudHJ5LT50YXNrLCBf
X2VudHJ5LT5jbG50LCBfX2VudHJ5LT5zdGF0dXMpDQo+ICspOw0KPiArDQo+ICtERUZJTkVfRVZF
TlQocnBjX3Rhc2tfc3RhdHVzLCBycGNfY2FsbF9zdGF0dXMsDQo+ICsJVFBfUFJPVE8oc3RydWN0
IHJwY190YXNrICp0YXNrKSwgDQo+ICsNCj4gKwlUUF9BUkdTKHRhc2spDQo+ICspOw0KPiArDQo+
ICtERUZJTkVfRVZFTlQocnBjX3Rhc2tfc3RhdHVzLCBycGNfYmluZF9zdGF0dXMsDQo+ICsJVFBf
UFJPVE8oc3RydWN0IHJwY190YXNrICp0YXNrKSwgDQo+ICsNCj4gKwlUUF9BUkdTKHRhc2spDQo+
ICspOw0KPiArDQo+ICtUUkFDRV9FVkVOVChycGNfY29ubmVjdF9zdGF0dXMsDQo+ICsJVFBfUFJP
VE8oc3RydWN0IHJwY190YXNrICp0YXNrLCBpbnQgc3RhdHVzKSwNCj4gKw0KPiArCVRQX0FSR1Mo
dGFzaywgc3RhdHVzKSwNCj4gKw0KPiArCVRQX1NUUlVDVF9fZW50cnkoDQo+ICsJCV9fZmllbGQo
Y29uc3Qgc3RydWN0IHJwY190YXNrICosIHRhc2spDQo+ICsJCV9fZmllbGQoY29uc3Qgc3RydWN0
IHJwY19jbG50ICosIGNsbnQpDQo+ICsJCV9fZmllbGQoaW50LCBzdGF0dXMpDQo+ICsJKSwNCj4g
Kw0KPiArCVRQX2Zhc3RfYXNzaWduKA0KPiArCQlfX2VudHJ5LT50YXNrID0gdGFzazsNCj4gKwkJ
X19lbnRyeS0+Y2xudCA9IHRhc2stPnRrX2NsaWVudDsNCj4gKwkJX19lbnRyeS0+c3RhdHVzID0g
c3RhdHVzOw0KPiArCSksDQo+ICsNCj4gKwlUUF9wcmludGsoInRhc2s6JXBAJXAsIHN0YXR1cyAl
ZCIsX19lbnRyeS0+dGFzaywgX19lbnRyeS0+Y2xudCwgX19lbnRyeS0+c3RhdHVzKQ0KPiArKTsN
Cj4gKw0KPiAgREVDTEFSRV9FVkVOVF9DTEFTUyhycGNfdGFza19ydW5uaW5nLA0KPiAgDQoNCg0K
VGhpcyBodW5rIGRpZCBjb250YWluIGEgY291cGxlIG9mIHRyYWlsaW5nIHdoaXRlc3BhY2UgZXJy
b3JzLCBidXQgSSd2ZQ0KZml4ZWQgdGhlbSB1cCBhbmQgYXBwbGllZC4NCg==

Re: [PATCH v3 2/2] SUNRPC: Adding status trace points

[Steve Dickson]

On 02/06/2012 10:39 AM, Myklebust, Trond wrote:
> On Mon, 2012-02-06 at 10:08 -0500, Steve Dickson wrote:
>> This patch adds three trace points to the status routines
>> in the sunrpc state machine.
>>
>> The goal of these trace points is to give an Admin
>> the ability to check on binding status or connection
>> status to see if there is a potential problem.
>>
>> Signed-off-by: Steve Dickson <steved@redhat.com>
>> ---
>>  include/trace/events/sunrpc.h |   53 +++++++++++++++++++++++++++++++++++++++++
>>  net/sunrpc/clnt.c             |    6 ++++-
>>  2 files changed, 58 insertions(+), 1 deletions(-)
>>
>> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
>> index 2f82de9..abcf45d 100644
>> --- a/include/trace/events/sunrpc.h
>> +++ b/include/trace/events/sunrpc.h
>> @@ -8,6 +8,59 @@
>>  #include <linux/sunrpc/clnt.h>
>>  #include <linux/tracepoint.h>
>>  
>> +DECLARE_EVENT_CLASS(rpc_task_status,
>> +
>> +	TP_PROTO(struct rpc_task *task),
>> +
>> +	TP_ARGS(task),
>> +
>> +	TP_STRUCT__entry(
>> +		__field(const struct rpc_task *, task)
>> +		__field(const struct rpc_clnt *, clnt)
>> +		__field(int, status)
>> +	),
>> +
>> +	TP_fast_assign(
>> +		__entry->task = task;
>> +		__entry->clnt = task->tk_client;
>> +		__entry->status = task->tk_status;
>> +	),
>> +
>> +	TP_printk("task:%p@%p, status %d",__entry->task, __entry->clnt, __entry->status)
>> +);
>> +
>> +DEFINE_EVENT(rpc_task_status, rpc_call_status,
>> +	TP_PROTO(struct rpc_task *task), 
>> +
>> +	TP_ARGS(task)
>> +);
>> +
>> +DEFINE_EVENT(rpc_task_status, rpc_bind_status,
>> +	TP_PROTO(struct rpc_task *task), 
>> +
>> +	TP_ARGS(task)
>> +);
>> +
>> +TRACE_EVENT(rpc_connect_status,
>> +	TP_PROTO(struct rpc_task *task, int status),
>> +
>> +	TP_ARGS(task, status),
>> +
>> +	TP_STRUCT__entry(
>> +		__field(const struct rpc_task *, task)
>> +		__field(const struct rpc_clnt *, clnt)
>> +		__field(int, status)
>> +	),
>> +
>> +	TP_fast_assign(
>> +		__entry->task = task;
>> +		__entry->clnt = task->tk_client;
>> +		__entry->status = status;
>> +	),
>> +
>> +	TP_printk("task:%p@%p, status %d",__entry->task, __entry->clnt, __entry->status)
>> +);
>> +
>>  DECLARE_EVENT_CLASS(rpc_task_running,
>>  
> 
> 
> This hunk did contain a couple of trailing whitespace errors, but I've
> fixed them up and applied.
Hmm... Sorry about... I wonder how that happen... any ways thanks!

steved.

Re: [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem

[Christoph Hellwig]

> +	TP_STRUCT__entry(
> +		__field(const struct rpc_clnt *, clnt)
> +		__field(const struct rpc_task *, task)
> +		__field(const void *, action)
> +		__field(unsigned long, runstate)
> +		__field(int, status)
> +		__field(unsigned short, flags)

Storing pointers in the trace buffer is not safe for reuse later,
and just printing the pointer values isn't overly useful either.  Please
redesign these tracepoint to be a bit more useful.

Re: [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem

[Myklebust, Trond]

T24gTW9uLCAyMDEyLTAyLTA2IGF0IDEyOjQ3IC0wNTAwLCBDaHJpc3RvcGggSGVsbHdpZyB3cm90
ZToNCj4gPiArCVRQX1NUUlVDVF9fZW50cnkoDQo+ID4gKwkJX19maWVsZChjb25zdCBzdHJ1Y3Qg
cnBjX2NsbnQgKiwgY2xudCkNCj4gPiArCQlfX2ZpZWxkKGNvbnN0IHN0cnVjdCBycGNfdGFzayAq
LCB0YXNrKQ0KPiA+ICsJCV9fZmllbGQoY29uc3Qgdm9pZCAqLCBhY3Rpb24pDQo+ID4gKwkJX19m
aWVsZCh1bnNpZ25lZCBsb25nLCBydW5zdGF0ZSkNCj4gPiArCQlfX2ZpZWxkKGludCwgc3RhdHVz
KQ0KPiA+ICsJCV9fZmllbGQodW5zaWduZWQgc2hvcnQsIGZsYWdzKQ0KPiANCj4gU3RvcmluZyBw
b2ludGVycyBpbiB0aGUgdHJhY2UgYnVmZmVyIGlzIG5vdCBzYWZlIGZvciByZXVzZSBsYXRlciwN
Cj4gYW5kIGp1c3QgcHJpbnRpbmcgdGhlIHBvaW50ZXIgdmFsdWVzIGlzbid0IG92ZXJseSB1c2Vm
dWwgZWl0aGVyLiAgUGxlYXNlDQo+IHJlZGVzaWduIHRoZXNlIHRyYWNlcG9pbnQgdG8gYmUgYSBi
aXQgbW9yZSB1c2VmdWwuDQoNClRoZSBwb2ludGVyIHZhbHVlcyBhcmUganVzdCB1c2VkIGFzIGxh
YmVscyB0byBpZGVudGlmeSB0aGUgcnBjX3Rhc2sgYW5kDQpycGNfY2xudCB0aGF0IGlzIGJlaW5n
IHRyYWNrZWQuIFRoZSBtYWluIGluZm9ybWF0aW9uIGlzIGNhcnJpZWQgaW4gdGhlDQpydW5zdGF0
ZSwgc3RhdHVzIGFuZCBmbGFncywgd2hpY2ggYXJlIHN0b3JlZCBhcy1pcy4NCg0KDQo=