SUNRPC: Add tracepoints for dropped and deferred requests
authorTrond Myklebust <trond.myklebust@primarydata.com>
Fri, 24 Jun 2016 14:55:46 +0000 (10:55 -0400)
committerJ. Bruce Fields <bfields@redhat.com>
Wed, 13 Jul 2016 19:53:43 +0000 (15:53 -0400)
Dropping and/or deferring requests has an impact on performance. Let's
make sure we can trace those events.

Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
include/trace/events/sunrpc.h
net/sunrpc/svc_xprt.c

index b014207a95a863cacb089dbe28a3f088bdcbbd35..8a707f8a41c3df76b682032cf180eda869a49e1d 100644 (file)
@@ -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 <trace/define_trace.h>
index 4d2189a562af00f5eb47ad794bfe4596c73e472e..e7082a4aeb56e4e7003d96ee38775ec2acca48c7 100644 (file)
@@ -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);