From db1bb44c4c7e8d49ed674dc59e5222d99c698088 Mon Sep 17 00:00:00 2001 From: Trond Myklebust Date: Fri, 24 Jun 2016 10:55:44 -0400 Subject: SUNRPC: Don't allocate a full sockaddr_storage for tracing We're always tracing IPv4 or IPv6 addresses, so we can save a lot of space on the ringbuffer by allocating the correct sockaddr size. Signed-off-by: Trond Myklebust Cc: stable@vger.kernel.org Fixes: 83a712e0afef "sunrpc: add some tracepoints around ..." Signed-off-by: J. Bruce Fields --- include/trace/events/sunrpc.h | 47 +++++++++++++++++++++++++++++++------------ 1 file changed, 34 insertions(+), 13 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 003dca933803..5664ca07c9c7 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -529,20 +529,27 @@ TRACE_EVENT(svc_xprt_do_enqueue, TP_STRUCT__entry( __field(struct svc_xprt *, xprt) - __field_struct(struct sockaddr_storage, ss) __field(int, pid) __field(unsigned long, flags) + __dynamic_array(unsigned char, addr, xprt != NULL ? + xprt->xpt_remotelen : 0) ), TP_fast_assign( __entry->xprt = xprt; - xprt ? memcpy(&__entry->ss, &xprt->xpt_remote, sizeof(__entry->ss)) : memset(&__entry->ss, 0, sizeof(__entry->ss)); __entry->pid = rqst? rqst->rq_task->pid : 0; - __entry->flags = xprt ? xprt->xpt_flags : 0; + if (xprt) { + memcpy(__get_dynamic_array(addr), + &xprt->xpt_remote, + xprt->xpt_remotelen); + __entry->flags = xprt->xpt_flags; + } else + __entry->flags = 0; ), TP_printk("xprt=0x%p addr=%pIScp pid=%d flags=%s", __entry->xprt, - (struct sockaddr *)&__entry->ss, + __get_dynamic_array_len(addr) != 0 ? + (struct sockaddr *)__get_dynamic_array(addr) : NULL, __entry->pid, show_svc_xprt_flags(__entry->flags)) ); @@ -553,18 +560,25 @@ TRACE_EVENT(svc_xprt_dequeue, TP_STRUCT__entry( __field(struct svc_xprt *, xprt) - __field_struct(struct sockaddr_storage, ss) __field(unsigned long, flags) + __dynamic_array(unsigned char, addr, xprt != NULL ? + xprt->xpt_remotelen : 0) ), TP_fast_assign( - __entry->xprt = xprt, - xprt ? memcpy(&__entry->ss, &xprt->xpt_remote, sizeof(__entry->ss)) : memset(&__entry->ss, 0, sizeof(__entry->ss)); - __entry->flags = xprt ? xprt->xpt_flags : 0; + __entry->xprt = xprt; + if (xprt) { + memcpy(__get_dynamic_array(addr), + &xprt->xpt_remote, + xprt->xpt_remotelen); + __entry->flags = xprt->xpt_flags; + } else + __entry->flags = 0; ), TP_printk("xprt=0x%p addr=%pIScp flags=%s", __entry->xprt, - (struct sockaddr *)&__entry->ss, + __get_dynamic_array_len(addr) != 0 ? + (struct sockaddr *)__get_dynamic_array(addr) : NULL, show_svc_xprt_flags(__entry->flags)) ); @@ -592,19 +606,26 @@ TRACE_EVENT(svc_handle_xprt, TP_STRUCT__entry( __field(struct svc_xprt *, xprt) __field(int, len) - __field_struct(struct sockaddr_storage, ss) __field(unsigned long, flags) + __dynamic_array(unsigned char, addr, xprt != NULL ? + xprt->xpt_remotelen : 0) ), TP_fast_assign( __entry->xprt = xprt; - xprt ? memcpy(&__entry->ss, &xprt->xpt_remote, sizeof(__entry->ss)) : memset(&__entry->ss, 0, sizeof(__entry->ss)); __entry->len = len; - __entry->flags = xprt ? xprt->xpt_flags : 0; + if (xprt) { + memcpy(__get_dynamic_array(addr), + &xprt->xpt_remote, + xprt->xpt_remotelen); + __entry->flags = xprt->xpt_flags; + } else + __entry->flags = 0; ), TP_printk("xprt=0x%p addr=%pIScp len=%d flags=%s", __entry->xprt, - (struct sockaddr *)&__entry->ss, + __get_dynamic_array_len(addr) != 0 ? + (struct sockaddr *)__get_dynamic_array(addr) : NULL, __entry->len, show_svc_xprt_flags(__entry->flags)) ); #endif /* _TRACE_SUNRPC_H */ -- cgit v1.2.3 From 82ea2d7615309d755579d609ad9c11daea25d0cc Mon Sep 17 00:00:00 2001 From: Trond Myklebust Date: Fri, 24 Jun 2016 10:55:45 -0400 Subject: SUNRPC: Add a tracepoint for server socket out-of-space conditions Add a tracepoint to track when the processing of incoming RPC data gets deferred due to out-of-space issues on the outgoing transport. Signed-off-by: Trond Myklebust Signed-off-by: J. Bruce Fields --- include/trace/events/sunrpc.h | 10 +++++++++- net/sunrpc/svc_xprt.c | 8 ++++++-- 2 files changed, 15 insertions(+), 3 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 5664ca07c9c7..b014207a95a8 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -553,7 +553,7 @@ TRACE_EVENT(svc_xprt_do_enqueue, __entry->pid, show_svc_xprt_flags(__entry->flags)) ); -TRACE_EVENT(svc_xprt_dequeue, +DECLARE_EVENT_CLASS(svc_xprt_event, TP_PROTO(struct svc_xprt *xprt), TP_ARGS(xprt), @@ -582,6 +582,14 @@ TRACE_EVENT(svc_xprt_dequeue, show_svc_xprt_flags(__entry->flags)) ); +DEFINE_EVENT(svc_xprt_event, svc_xprt_dequeue, + TP_PROTO(struct svc_xprt *xprt), + TP_ARGS(xprt)); + +DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space, + TP_PROTO(struct svc_xprt *xprt), + TP_ARGS(xprt)); + TRACE_EVENT(svc_wake_up, TP_PROTO(int pid), diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c index 4f01f63102ee..4d2189a562af 100644 --- a/net/sunrpc/svc_xprt.c +++ b/net/sunrpc/svc_xprt.c @@ -333,8 +333,12 @@ static bool svc_xprt_has_something_to_do(struct svc_xprt *xprt) { if (xprt->xpt_flags & ((1<xpt_flags & ((1<xpt_ops->xpo_has_wspace(xprt); + if (xprt->xpt_flags & ((1<xpt_ops->xpo_has_wspace(xprt)) + return true; + trace_svc_xprt_no_write_space(xprt); + return false; + } return false; } -- cgit v1.2.3 From 104f6351f7dc0036575b4e47765d6d39c757c066 Mon Sep 17 00:00:00 2001 From: Trond Myklebust Date: Fri, 24 Jun 2016 10:55:46 -0400 Subject: SUNRPC: Add tracepoints for dropped and deferred requests Dropping and/or deferring requests has an impact on performance. Let's make sure we can trace those events. Signed-off-by: Trond Myklebust Signed-off-by: J. Bruce Fields --- include/trace/events/sunrpc.h | 61 +++++++++++++++++++++++++++++++++++++++++++ net/sunrpc/svc_xprt.c | 4 +++ 2 files changed, 65 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index b014207a95a8..8a707f8a41c3 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -473,6 +473,39 @@ TRACE_EVENT(svc_recv, show_rqstp_flags(__entry->flags)) ); +DECLARE_EVENT_CLASS(svc_rqst_event, + + TP_PROTO(struct svc_rqst *rqst), + + TP_ARGS(rqst), + + TP_STRUCT__entry( + __field(__be32, xid) + __field(unsigned long, flags) + __dynamic_array(unsigned char, addr, rqst->rq_addrlen) + ), + + TP_fast_assign( + __entry->xid = rqst->rq_xid; + __entry->flags = rqst->rq_flags; + memcpy(__get_dynamic_array(addr), + &rqst->rq_addr, rqst->rq_addrlen); + ), + + TP_printk("addr=%pIScp rq_xid=0x%x flags=%s", + (struct sockaddr *)__get_dynamic_array(addr), + be32_to_cpu(__entry->xid), + show_rqstp_flags(__entry->flags)) +); + +DEFINE_EVENT(svc_rqst_event, svc_defer, + TP_PROTO(struct svc_rqst *rqst), + TP_ARGS(rqst)); + +DEFINE_EVENT(svc_rqst_event, svc_drop, + TP_PROTO(struct svc_rqst *rqst), + TP_ARGS(rqst)); + DECLARE_EVENT_CLASS(svc_rqst_status, TP_PROTO(struct svc_rqst *rqst, int status), @@ -636,6 +669,34 @@ TRACE_EVENT(svc_handle_xprt, (struct sockaddr *)__get_dynamic_array(addr) : NULL, __entry->len, show_svc_xprt_flags(__entry->flags)) ); + + +DECLARE_EVENT_CLASS(svc_deferred_event, + TP_PROTO(struct svc_deferred_req *dr), + + TP_ARGS(dr), + + TP_STRUCT__entry( + __field(__be32, xid) + __dynamic_array(unsigned char, addr, dr->addrlen) + ), + + TP_fast_assign( + __entry->xid = *(__be32 *)(dr->args + (dr->xprt_hlen>>2)); + memcpy(__get_dynamic_array(addr), &dr->addr, dr->addrlen); + ), + + TP_printk("addr=%pIScp xid=0x%x", + (struct sockaddr *)__get_dynamic_array(addr), + be32_to_cpu(__entry->xid)) +); + +DEFINE_EVENT(svc_deferred_event, svc_drop_deferred, + TP_PROTO(struct svc_deferred_req *dr), + TP_ARGS(dr)); +DEFINE_EVENT(svc_deferred_event, svc_revisit_deferred, + TP_PROTO(struct svc_deferred_req *dr), + TP_ARGS(dr)); #endif /* _TRACE_SUNRPC_H */ #include diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c index 4d2189a562af..e7082a4aeb56 100644 --- a/net/sunrpc/svc_xprt.c +++ b/net/sunrpc/svc_xprt.c @@ -875,6 +875,7 @@ EXPORT_SYMBOL_GPL(svc_recv); */ void svc_drop(struct svc_rqst *rqstp) { + trace_svc_drop(rqstp); dprintk("svc: xprt %p dropped request\n", rqstp->rq_xprt); svc_xprt_release(rqstp); } @@ -1152,6 +1153,7 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many) spin_unlock(&xprt->xpt_lock); dprintk("revisit canceled\n"); svc_xprt_put(xprt); + trace_svc_drop_deferred(dr); kfree(dr); return; } @@ -1209,6 +1211,7 @@ static struct cache_deferred_req *svc_defer(struct cache_req *req) set_bit(RQ_DROPME, &rqstp->rq_flags); dr->handle.revisit = svc_revisit; + trace_svc_defer(rqstp); return &dr->handle; } @@ -1249,6 +1252,7 @@ static struct svc_deferred_req *svc_deferred_dequeue(struct svc_xprt *xprt) struct svc_deferred_req, handle.recent); list_del_init(&dr->handle.recent); + trace_svc_revisit_deferred(dr); } else clear_bit(XPT_DEFERRED, &xprt->xpt_flags); spin_unlock(&xprt->xpt_lock); -- cgit v1.2.3