* [PATCH v3 0/2] SUNRPC: Added Tracing Points @ 2012-02-06 15:08 Steve Dickson 2012-02-06 15:08 ` [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem Steve Dickson 2012-02-06 15:08 ` [PATCH v3 2/2] SUNRPC: Adding status trace points Steve Dickson 0 siblings, 2 replies; 8+ messages in thread From: Steve Dickson @ 2012-02-06 15:08 UTC (permalink / raw) To: Trond Myklebust; +Cc: Linux NFS Mailing List [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 ^ permalink raw reply [flat|nested] 8+ messages in thread
* [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem 2012-02-06 15:08 [PATCH v3 0/2] SUNRPC: Added Tracing Points Steve Dickson @ 2012-02-06 15:08 ` Steve Dickson 2012-02-06 17:47 ` Christoph Hellwig 2012-02-06 15:08 ` [PATCH v3 2/2] SUNRPC: Adding status trace points Steve Dickson 1 sibling, 1 reply; 8+ messages in thread From: Steve Dickson @ 2012-02-06 15:08 UTC (permalink / raw) To: Trond Myklebust; +Cc: Linux NFS Mailing List 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 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem 2012-02-06 15:08 ` [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem Steve Dickson @ 2012-02-06 17:47 ` Christoph Hellwig 2012-02-06 18:21 ` Myklebust, Trond 0 siblings, 1 reply; 8+ messages in thread From: Christoph Hellwig @ 2012-02-06 17:47 UTC (permalink / raw) To: Steve Dickson; +Cc: Trond Myklebust, Linux NFS Mailing List > + 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. ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem 2012-02-06 17:47 ` Christoph Hellwig @ 2012-02-06 18:21 ` Myklebust, Trond 0 siblings, 0 replies; 8+ messages in thread From: Myklebust, Trond @ 2012-02-06 18:21 UTC (permalink / raw) To: Christoph Hellwig; +Cc: Steve Dickson, Linux NFS Mailing List T24gTW9uLCAyMDEyLTAyLTA2IGF0IDEyOjQ3IC0wNTAwLCBDaHJpc3RvcGggSGVsbHdpZyB3cm90 ZToNCj4gPiArCVRQX1NUUlVDVF9fZW50cnkoDQo+ID4gKwkJX19maWVsZChjb25zdCBzdHJ1Y3Qg cnBjX2NsbnQgKiwgY2xudCkNCj4gPiArCQlfX2ZpZWxkKGNvbnN0IHN0cnVjdCBycGNfdGFzayAq LCB0YXNrKQ0KPiA+ICsJCV9fZmllbGQoY29uc3Qgdm9pZCAqLCBhY3Rpb24pDQo+ID4gKwkJX19m aWVsZCh1bnNpZ25lZCBsb25nLCBydW5zdGF0ZSkNCj4gPiArCQlfX2ZpZWxkKGludCwgc3RhdHVz KQ0KPiA+ICsJCV9fZmllbGQodW5zaWduZWQgc2hvcnQsIGZsYWdzKQ0KPiANCj4gU3RvcmluZyBw b2ludGVycyBpbiB0aGUgdHJhY2UgYnVmZmVyIGlzIG5vdCBzYWZlIGZvciByZXVzZSBsYXRlciwN Cj4gYW5kIGp1c3QgcHJpbnRpbmcgdGhlIHBvaW50ZXIgdmFsdWVzIGlzbid0IG92ZXJseSB1c2Vm dWwgZWl0aGVyLiAgUGxlYXNlDQo+IHJlZGVzaWduIHRoZXNlIHRyYWNlcG9pbnQgdG8gYmUgYSBi aXQgbW9yZSB1c2VmdWwuDQoNClRoZSBwb2ludGVyIHZhbHVlcyBhcmUganVzdCB1c2VkIGFzIGxh YmVscyB0byBpZGVudGlmeSB0aGUgcnBjX3Rhc2sgYW5kDQpycGNfY2xudCB0aGF0IGlzIGJlaW5n IHRyYWNrZWQuIFRoZSBtYWluIGluZm9ybWF0aW9uIGlzIGNhcnJpZWQgaW4gdGhlDQpydW5zdGF0 ZSwgc3RhdHVzIGFuZCBmbGFncywgd2hpY2ggYXJlIHN0b3JlZCBhcy1pcy4NCg0KDQo= ^ permalink raw reply [flat|nested] 8+ messages in thread
* [PATCH v3 2/2] SUNRPC: Adding status trace points 2012-02-06 15:08 [PATCH v3 0/2] SUNRPC: Added Tracing Points Steve Dickson 2012-02-06 15:08 ` [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem Steve Dickson @ 2012-02-06 15:08 ` Steve Dickson 2012-02-06 15:39 ` Myklebust, Trond 1 sibling, 1 reply; 8+ messages in thread From: Steve Dickson @ 2012-02-06 15:08 UTC (permalink / raw) To: Trond Myklebust; +Cc: Linux NFS Mailing List 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 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH v3 2/2] SUNRPC: Adding status trace points 2012-02-06 15:08 ` [PATCH v3 2/2] SUNRPC: Adding status trace points Steve Dickson @ 2012-02-06 15:39 ` Myklebust, Trond 2012-02-06 17:30 ` Steve Dickson 0 siblings, 1 reply; 8+ messages in thread From: Myklebust, Trond @ 2012-02-06 15:39 UTC (permalink / raw) To: Steve Dickson; +Cc: Linux NFS Mailing List 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== ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v3 2/2] SUNRPC: Adding status trace points 2012-02-06 15:39 ` Myklebust, Trond @ 2012-02-06 17:30 ` Steve Dickson 0 siblings, 0 replies; 8+ messages in thread From: Steve Dickson @ 2012-02-06 17:30 UTC (permalink / raw) To: Myklebust, Trond; +Cc: Linux NFS Mailing List 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. ^ permalink raw reply [flat|nested] 8+ messages in thread
* [PATCH 0/2] SUNRPC: Added Tracing Points @ 2012-01-24 20:51 Steve Dickson 2012-01-24 20:51 ` [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem Steve Dickson 0 siblings, 1 reply; 8+ messages in thread From: Steve Dickson @ 2012-01-24 20:51 UTC (permalink / raw) To: Linux NFS Mailing list 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 as well as being called from a systemtab prob. 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 ^ permalink raw reply [flat|nested] 8+ messages in thread
* [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem 2012-01-24 20:51 [PATCH 0/2] SUNRPC: Added Tracing Points Steve Dickson @ 2012-01-24 20:51 ` Steve Dickson 0 siblings, 0 replies; 8+ messages in thread From: Steve Dickson @ 2012-01-24 20:51 UTC (permalink / raw) To: Linux NFS Mailing list 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 ^ permalink raw reply related [flat|nested] 8+ messages in thread
end of thread, other threads:[~2012-02-06 19:17 UTC | newest] Thread overview: 8+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2012-02-06 15:08 [PATCH v3 0/2] SUNRPC: Added Tracing Points Steve Dickson 2012-02-06 15:08 ` [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem Steve Dickson 2012-02-06 17:47 ` Christoph Hellwig 2012-02-06 18:21 ` Myklebust, Trond 2012-02-06 15:08 ` [PATCH v3 2/2] SUNRPC: Adding status trace points Steve Dickson 2012-02-06 15:39 ` Myklebust, Trond 2012-02-06 17:30 ` Steve Dickson -- strict thread matches above, loose matches on Subject: below -- 2012-01-24 20:51 [PATCH 0/2] SUNRPC: Added Tracing Points Steve Dickson 2012-01-24 20:51 ` [PATCH v3 1/2] SUNRPC: Add trace events to the sunrpc subsystem Steve Dickson
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).